Skip to content

Instantly share code, notes, and snippets.

@eregon

eregon/bench_marshal_load.rb Secret

Last active September 1, 2020 10:45
Show Gist options
  • Save eregon/e523df1b607bd152a9eef980fd936b8c to your computer and use it in GitHub Desktop.
Save eregon/e523df1b607bd152a9eef980fd936b8c to your computer and use it in GitHub Desktop.
Download ZIP
Raw
bench_marshal_load.rb
require 'benchmark'
# require 'benchmark/ips'
file = "dump-#{RUBY_ENGINE}-#{RUBY_ENGINE_VERSION}.marshal"
dump = if File.exist?(file)
File.binread(file)
else
alphabet = "A, B, C, D, E, F, G, H, I, J, K, L, M, N, O, P, Q, R, S, T, U, V, W, X, Y, Z".split(", ")
symalphabet = [:AA, :AB, :AC, :AD, :AE, :AF, :AG, :AH, :AI, :AJ,
:BA, :BB, :BC, :BD, :BE, :BF, :BG, :BH, :BI, :BJ,
:CA, :CB, :CC, :CD, :CE, :CF, :CG, :CH, :CI, :CJ,
:DA, :DB, :DC, :DD, :DE, :DF, :DG, :DH, :DI, :DJ,
:EA, :EB, :EC, :ED, :EE, :EF, :EG, :EH, :EI, :EJ,
:FA, :FB, :FC, :FD, :FE, :FF, :FG, :FH, :FI, :FJ,
:GA, :GB, :GC, :GD, :GE, :GF, :GG, :GH, :GI, :GJ,
:HA, :HB, :HC, :HD, :HE, :HF, :HG, :HH, :HI, :HJ,
:IA, :IB, :IC, :ID, :IE, :IF, :IG, :IH, :II, :IJ,
:JA, :JB, :JC, :JD, :JE, :JF, :JG, :JH, :JI, :JJ,
]
bigh = Hash.new
alphabet.each do |letter1|
alphabet.each do |letter2|
h = Hash.new
symalphabet.each do |symbol|
h[symbol] = {:a => "String One", :b => "String Two", :c => nil}
end
bigh[letter1+letter2] = h
end
end
str = Marshal.dump(bigh)
File.binwrite(file, str)
str
end
puts Benchmark.measure { Marshal.load(dump) }
# Benchmark.ips do |x|
# x.warmup = 5
# x.report('Marshal.load') { Marshal.load(dump) }
# end
Raw
inlining.txt
Inlining for the last compilation of Marshal::State#construct when doing a single Marshal.load:
[engine] Inline start Marshal::State#construct |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio 1.13 |IR Nodes 24647 |Frequency 1.00 |Truffle Callees 35 |Forced false |Depth 0
[engine] Inlined Marshal::StringState#consume_byte |call diff -2.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 1134 |Frequency 1.00 |Truffle Callees 1 |Forced false |Depth 1
[engine] Inlined Array#[] <split-461b1e40> |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 186 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 2
[engine] Inlined Integer#=== |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 99 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Inlined Integer#=== |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 99 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Inlined Integer#=== |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 99 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Inlined Integer#=== |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 99 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Inlined Integer#=== |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 99 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Inlined Integer#=== |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 99 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Inlined Integer#=== |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 99 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Inlined Integer#=== |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 99 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Inlined Integer#=== |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 99 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Inlined Integer#=== |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 99 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Inlined Marshal::State#construct_symbol |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 406 |Frequency 0.00 |Truffle Callees 3 |Forced false |Depth 1
[engine] Inlined Marshal::State#get_byte_sequence |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 282 |Frequency 0.00 |Truffle Callees 2 |Forced false |Depth 2
[engine] Inlined Marshal::State#construct_integer |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 749 |Frequency 0.00 |Truffle Callees 5 |Forced false |Depth 3
[engine] Inlined Marshal::StringState#consume_byte |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 1134 |Frequency 0.00 |Truffle Callees 1 |Forced false |Depth 4
[engine] Inlined Array#[] <split-461b1e40> |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 186 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 5
[engine] Cutoff Integer#=== |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 4
[engine] Cutoff Integer#=== |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 4
[engine] Cutoff Marshal::StringState#consume_byte |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 1 |Forced false |Depth 4
[engine] Cutoff Marshal::StringState#consume_byte |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 1 |Forced false |Depth 4
[engine] Inlined Marshal::StringState#consume |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 1170 |Frequency 0.00 |Truffle Callees 1 |Forced false |Depth 3
[engine] Inlined String#byteslice |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 1078 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 4
[engine] Inlined String#to_sym <split-5f909e0b> |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 88 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 2
[engine] Inlined Marshal::State#store_unique_object <split-7e721b0b> |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 245 |Frequency 0.00 |Truffle Callees 1 |Forced false |Depth 2
[engine] Inlined Marshal::State#add_symlink |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 853 |Frequency 0.00 |Truffle Callees 4 |Forced false |Depth 3
[engine] Inlined Hash#size |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 77 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 4
[engine] Inlined Array#[]= <split-56bd7506> |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 370 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 4
[engine] Inlined BasicObject#__id__ |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 635 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 4
[engine] Expanded Hash#[]= <split-821deea> |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 795 |Frequency 0.00 |Truffle Callees 2 |Forced false |Depth 4
[engine] Inlined Integer#=== |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 99 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Inlined Marshal::State#construct_string |call diff -16.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 484 |Frequency 1.00 |Truffle Callees 3 |Forced false |Depth 1
[engine] Inlined Marshal::State#get_byte_sequence |call diff -6.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 282 |Frequency 1.00 |Truffle Callees 2 |Forced false |Depth 2
[engine] Inlined Marshal::State#construct_integer |call diff -3.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 749 |Frequency 1.00 |Truffle Callees 5 |Forced false |Depth 3
[engine] Inlined Marshal::StringState#consume_byte |call diff -2.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 1134 |Frequency 1.00 |Truffle Callees 1 |Forced false |Depth 4
[engine] Inlined Array#[] <split-461b1e40> |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 186 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 5
[engine] Inlined Integer#=== |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 99 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 4
[engine] Inlined Integer#=== |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 99 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 4
[engine] Inlined Marshal::StringState#consume_byte |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 1134 |Frequency 0.00 |Truffle Callees 1 |Forced false |Depth 4
[engine] Inlined Array#[] <split-461b1e40> |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 186 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 5
[engine] Inlined Marshal::StringState#consume_byte |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 1134 |Frequency 0.00 |Truffle Callees 1 |Forced false |Depth 4
[engine] Inlined Array#[] <split-461b1e40> |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 186 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 5
[engine] Inlined Marshal::StringState#consume |call diff -2.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 1170 |Frequency 1.00 |Truffle Callees 1 |Forced false |Depth 3
[engine] Inlined String#byteslice |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 1078 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 4
[engine] Inlined String#force_encoding |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 285 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 2
[engine] Inlined Marshal::State#store_unique_object <split-7b83e3b4> |call diff -8.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 256 |Frequency 1.00 |Truffle Callees 1 |Forced false |Depth 2
[engine] Inlined Marshal::State#add_non_immediate_object <split-37cd58ce>|call diff -7.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 252 |Frequency 1.00 |Truffle Callees 1 |Forced false |Depth 3
[engine] Inlined Marshal::State#add_object <split-5016fcce> |call diff -6.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 871 |Frequency 1.00 |Truffle Callees 4 |Forced false |Depth 4
[engine] Inlined Array#size |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 63 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 5
[engine] Inlined Array#[]= <split-168ffbe9> |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 309 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 5
[engine] Inlined BasicObject#__id__ |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 635 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 5
[engine] Inlined Hash#[]= <split-235cf7a4> |call diff -2.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 545 |Frequency 1.00 |Truffle Callees 2 |Forced false |Depth 5
[engine] Inlined Kernel#hash |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 145 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 6
[engine] Cutoff Numeric#eql? |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 3 |Forced false |Depth 6
[engine] Inlined Integer#=== |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 99 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Inlined Integer#=== |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 99 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Inlined Integer#=== |call diff -0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 99 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Expanded Marshal::State#construct_hash |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 728 |Frequency 0.00 |Truffle Callees 3 |Forced false |Depth 1
[engine] Cutoff Integer#=== |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Cutoff Integer#=== |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Cutoff Integer#=== |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Cutoff Integer#=== |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Cutoff Integer#=== |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Cutoff Integer#=== |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Cutoff Integer#=== |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Cutoff Integer#=== |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Cutoff Integer#=== |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Cutoff Integer#=== |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Cutoff Integer#=== |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Cutoff Array#length |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Cutoff Array#push |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Cutoff Marshal::State#construct |call diff 0.00 |Recursion Depth 1 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 35 |Forced false |Depth 1
[engine] Cutoff Array#pop |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Cutoff Marshal::State#set_instance_variables |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 0 |Frequency 0.00 |Truffle Callees 2 |Forced false |Depth 1
[engine] Inlined Kernel#tainted? |call diff -1.00 |Recursion Depth 0 |Explore/inline ratio NaN |IR Nodes 64 |Frequency 1.00 |Truffle Callees 0 |Forced false |Depth 1
[engine] Inline done Marshal::State#construct |call diff 0.00 |Recursion Depth 0 |Explore/inline ratio 1.13 |IR Nodes 24647 |Frequency 1.00 |Truffle Callees 35 |Forced false |Depth 0
Raw
profile.txt
$ ruby -v
truffleruby 20.3.0-dev-06662f0c, like ruby 2.6.6, GraalVM CE Native [x86_64-linux]
$ ruby --experimental-options --cpusampler --cpusampler.SampleInternal bench_marshal_load.rb
4.898411 0.128468 5.026879 ( 2.202963)
--------------------------------------------------------------------------------------------------------------------------------------------------
Sampling Histogram. Recorded 1411 samples with period 1ms.
Self Time: Time spent on the top of the stack.
Total Time: Time spent somewhere on the stack.
Opt %: Percent of time spent in compiled and therefore non-interpreted code.
--------------------------------------------------------------------------------------------------------------------------------------------------
Thread: Thread[main,5,main]
Name | Total Time | Opt % || Self Time | Opt % | Location
--------------------------------------------------------------------------------------------------------------------------------------------------
Marshal::State#construct | 1371ms 97.2% | 0.0% || 455ms 32.2% | 6.4% | resource:/truffleruby/core/marshal.rb~561-654:14615-17159
Integer#=== | 183ms 13.0% | 100.0% || 183ms 13.0% | 100.0% | (core)~1:0
Marshal::State#add_object | 188ms 13.3% | 0.0% || 98ms 6.9% | 0.0% | resource:/truffleruby/core/marshal.rb~549-553:14384-14494
Marshal::State#store_unique_object | 327ms 23.2% | 2.8% || 86ms 6.1% | 10.5% | resource:/truffleruby/core/marshal.rb~1149-1156:28866-29021
block in Marshal::State#construct_hash | 1370ms 97.1% | 0.0% || 82ms 5.8% | 39.0% | resource:/truffleruby/core/marshal.rb~760:19325-19356
Marshal::State#construct_string | 393ms 27.9% | 1.5% || 73ms 5.2% | 8.2% | resource:/truffleruby/core/marshal.rb~229-252:7053-7724
Integer#times | 1370ms 97.1% | 0.0% || 55ms 3.9% | 34.5% | resource:/truffleruby/core/integer.rb~135-144:4106-4252
Marshal::State#add_non_immediate_object | 241ms 17.1% | 0.0% || 53ms 3.8% | 0.0% | resource:/truffleruby/core/marshal.rb~544-547:14253-14381
Marshal::State#get_byte_sequence | 66ms 4.7% | 50.0% || 42ms 3.0% | 78.6% | resource:/truffleruby/core/marshal.rb~945-948:23887-23969
Hash#[]= | 35ms 2.5% | 0.0% || 28ms 2.0% | 0.0% | (core)~1:0
Array#[]= | 26ms 1.8% | 0.0% || 26ms 1.8% | 0.0% | (core)~1:0
Marshal::StringState#consume_byte | 24ms 1.7% | 87.5% || 24ms 1.7% | 87.5% | resource:/truffleruby/core/marshal.rb~1262-1267:31843-32023
Marshal::State#construct_hash | 1370ms 97.1% | 0.0% || 18ms 1.3% | 0.0% | resource:/truffleruby/core/marshal.rb~756-772:19216-19636
Hash#[]= | 15ms 1.1% | 40.0% || 15ms 1.1% | 40.0% | (core)~1:0
$ ruby --experimental-options --cpusampler --cpusampler.SampleInternal bench_marshal_load.rb
4.869514 0.152891 5.022405 ( 2.183765)
----------------------------------------------------------------------------------------------------------------------------------------------------
Sampling Histogram. Recorded 1427 samples with period 1ms.
Self Time: Time spent on the top of the stack.
Total Time: Time spent somewhere on the stack.
Opt %: Percent of time spent in compiled and therefore non-interpreted code.
----------------------------------------------------------------------------------------------------------------------------------------------------
Thread: Thread[main,5,main]
Name | Total Time | Opt % || Self Time | Opt % | Location
----------------------------------------------------------------------------------------------------------------------------------------------------
Marshal::State#construct | 1385ms 97.1% | 0.0% || 491ms 34.4% | 0.4% | resource:/truffleruby/core/marshal.rb~561-654:14615-17159
Integer#=== | 167ms 11.7% | 100.0% || 167ms 11.7% | 100.0% | (core)~1:0
Marshal::State#construct_string | 246ms 17.2% | 26.0% || 102ms 7.1% | 62.7% | resource:/truffleruby/core/marshal.rb~229-252:7053-7724
block in Marshal::State#construct_hash | 1384ms 97.0% | 0.0% || 97ms 6.8% | 25.8% | resource:/truffleruby/core/marshal.rb~760:19325-19356
Integer#times | 1385ms 97.1% | 0.0% || 97ms 6.8% | 46.4% | resource:/truffleruby/core/integer.rb~135-144:4106-4252
Marshal::State#add_object | 160ms 11.2% | 0.0% || 74ms 5.2% | 0.0% | resource:/truffleruby/core/marshal.rb~549-553:14384-14494
Marshal::State#store_unique_object | 256ms 17.9% | 0.4% || 50ms 3.5% | 2.0% | resource:/truffleruby/core/marshal.rb~1149-1156:28866-29021
Marshal::State#add_non_immediate_object | 204ms 14.3% | 0.0% || 44ms 3.1% | 0.0% | resource:/truffleruby/core/marshal.rb~544-547:14253-14381
Hash#[]= | 26ms 1.8% | 0.0% || 24ms 1.7% | 0.0% | (core)~1:0
Marshal::State#construct_hash | 1385ms 97.1% | 0.0% || 22ms 1.5% | 0.0% | resource:/truffleruby/core/marshal.rb~756-772:19216-19636
Array#[]= | 22ms 1.5% | 0.0% || 22ms 1.5% | 0.0% | (core)~1:0
Marshal::StringState#consume_byte | 22ms 1.5% | 77.3% || 21ms 1.5% | 81.0% | resource:/truffleruby/core/marshal.rb~1262-1267:31843-32023
Hash#[]= | 20ms 1.4% | 0.0% || 19ms 1.3% | 0.0% | (core)~1:0
Marshal::State#set_object_encoding | 17ms 1.2% | 29.4% || 16ms 1.1% | 31.3% | resource:/truffleruby/core/marshal.rb~192-201:6136-6431
Raw
profile_roots.txt
$ ruby -v
truffleruby 20.3.0-dev-06662f0c, like ruby 2.6.6, GraalVM CE Native [x86_64-linux]
$ ruby --experimental-options --cpusampler --cpusampler.SampleInternal --cpusampler.Mode=roots bench_marshal_load.rb
7.377190 0.140224 7.517414 ( 3.230219)
--------------------------------------------------------------------------------------------------------------------------------------------------
Sampling Histogram. Recorded 2100 samples with period 1ms.
Self Time: Time spent on the top of the stack.
Total Time: Time spent somewhere on the stack.
Opt %: Percent of time spent in compiled and therefore non-interpreted code.
--------------------------------------------------------------------------------------------------------------------------------------------------
Thread: Thread[main,5,main]
Name | Total Time | Opt % || Self Time | Opt % | Location
--------------------------------------------------------------------------------------------------------------------------------------------------
Marshal::State#construct | 2059ms 98.0% | 0.0% || 920ms 43.8% | 3.6% | resource:/truffleruby/core/marshal.rb~561-654:14615-17159
Marshal::State#add_object | 259ms 12.3% | 6.2% || 150ms 7.1% | 0.0% | resource:/truffleruby/core/marshal.rb~549-553:14384-14494
block in Marshal::State#construct_hash | 2058ms 98.0% | 0.0% || 109ms 5.2% | 15.6% | resource:/truffleruby/core/marshal.rb~760:19325-19356
block in Marshal::State#set_instance_variables | 285ms 13.6% | 3.5% || 90ms 4.3% | 0.0% | resource:/truffleruby/core/marshal.rb~204:6470-6501
Marshal::State#store_unique_object | 423ms 20.1% | 12.3% || 88ms 4.2% | 2.3% | resource:/truffleruby/core/marshal.rb~1149-1156:28866-29021
Integer#times | 2058ms 98.0% | 0.0% || 81ms 3.9% | 17.3% | resource:/truffleruby/core/integer.rb~135-144:4106-4252
Marshal::State#construct_string | 426ms 20.3% | 10.6% || 79ms 3.8% | 1.3% | resource:/truffleruby/core/marshal.rb~229-252:7053-7724
Integer#=== | 78ms 3.7% | 100.0% || 78ms 3.7% | 100.0% | (core)~1:0
Marshal::State#add_non_immediate_object | 335ms 16.0% | 5.7% || 76ms 3.6% | 3.9% | resource:/truffleruby/core/marshal.rb~544-547:14253-14381
String#byteslice | 69ms 3.3% | 97.1% || 69ms 3.3% | 97.1% | resource:/truffleruby/core/string.rb~61-90:2492-3510
Hash#[]= | 41ms 2.0% | 24.4% || 41ms 2.0% | 24.4% | (core)~1:0
Marshal::State#construct_hash | 2058ms 98.0% | 0.0% || 35ms 1.7% | 0.0% | resource:/truffleruby/core/marshal.rb~756-772:19216-19636
Array#[]= | 31ms 1.5% | 6.5% || 31ms 1.5% | 6.5% | (core)~1:0
Marshal::StringState#consume | 90ms 4.3% | 64.4% || 22ms 1.0% | 9.1% | resource:/truffleruby/core/marshal.rb~1255-1260:31643-31840
Marshal::State#get_symbol | 109ms 5.2% | 11.0% || 20ms 1.0% | 0.0% | resource:/truffleruby/core/marshal.rb~956-969:24082-24336
$ ruby --experimental-options --cpusampler --cpusampler.SampleInternal --cpusampler.Mode=roots bench_marshal_load.rb
7.017792 0.130263 7.148055 ( 3.095496)
----------------------------------------------------------------------------------------------------------------------------------------------------
Sampling Histogram. Recorded 1991 samples with period 1ms.
Self Time: Time spent on the top of the stack.
Total Time: Time spent somewhere on the stack.
Opt %: Percent of time spent in compiled and therefore non-interpreted code.
----------------------------------------------------------------------------------------------------------------------------------------------------
Thread: Thread[main,5,main]
Name | Total Time | Opt % || Self Time | Opt % | Location
----------------------------------------------------------------------------------------------------------------------------------------------------
Marshal::State#construct | 1950ms 97.9% | 0.0% || 1018ms 51.1% | 7.3% | resource:/truffleruby/core/marshal.rb~561-654:14615-17159
block in Marshal::State#construct_hash | 1950ms 97.9% | 0.0% || 114ms 5.7% | 4.4% | resource:/truffleruby/core/marshal.rb~760:19325-19356
Marshal::State#add_object | 198ms 9.9% | 13.1% || 105ms 5.3% | 2.9% | resource:/truffleruby/core/marshal.rb~549-553:14384-14494
String#byteslice | 74ms 3.7% | 89.2% || 74ms 3.7% | 89.2% | resource:/truffleruby/core/string.rb~61-90:2492-3510
Integer#times | 1950ms 97.9% | 0.0% || 67ms 3.4% | 4.5% | resource:/truffleruby/core/integer.rb~135-144:4106-4252
Marshal::State#store_unique_object | 317ms 15.9% | 8.2% || 64ms 3.2% | 0.0% | resource:/truffleruby/core/marshal.rb~1149-1156:28866-29021
Integer#=== | 60ms 3.0% | 100.0% || 60ms 3.0% | 100.0% | (core)~1:0
Marshal::State#add_non_immediate_object | 252ms 12.7% | 10.3% || 54ms 2.7% | 0.0% | resource:/truffleruby/core/marshal.rb~544-547:14253-14381
Marshal::State#construct_hash | 1950ms 97.9% | 0.0% || 49ms 2.5% | 2.0% | resource:/truffleruby/core/marshal.rb~756-772:19216-19636
Marshal::State#construct_string | 296ms 14.9% | 25.3% || 41ms 2.1% | 2.4% | resource:/truffleruby/core/marshal.rb~229-252:7053-7724
block in Marshal::State#set_instance_variables | 275ms 13.8% | 34.9% || 37ms 1.9% | 5.4% | resource:/truffleruby/core/marshal.rb~204:6470-6501
Hash#[]= | 30ms 1.5% | 50.0% || 30ms 1.5% | 50.0% | (core)~1:0
Hash#[]= | 29ms 1.5% | 34.5% || 28ms 1.4% | 32.1% | (core)~1:0
Marshal::StringState#consume | 97ms 4.9% | 57.7% || 24ms 1.2% | 4.2% | resource:/truffleruby/core/marshal.rb~1255-1260:31643-31840
Hash#[]= | 25ms 1.3% | 4.0% || 24ms 1.2% | 4.2% | (core)~1:0
Array#[]= | 22ms 1.1% | 0.0% || 22ms 1.1% | 0.0% | (core)~1:0
Marshal::State#get_symbol | 170ms 8.5% | 37.6% || 20ms 1.0% | 10.0% | resource:/truffleruby/core/marshal.rb~956-969:24082-24336
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment