Skip to content

Instantly share code, notes, and snippets.

@TruffleSqueak-Bot

TruffleSqueak-Bot/5d99b29-1-summary.md

Created May 27, 2021 21:41
Show Gist options
  • Save TruffleSqueak-Bot/6fb0ac80e0ed367e32524a0762960332 to your computer and use it in GitHub Desktop.
Save TruffleSqueak-Bot/6fb0ac80e0ed367e32524a0762960332 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
5d99b29-1-summary.md

Steady (after 50 iterations)

Benchmark Name Min Geomean Median Mean Max Total (ms) Total (min)
Bounce 360 403 365.42 361 365.31 73083 1.22
DeltaBlue 156 227 188.06 186 187.92 37611 0.63
Havlak 1018 1120 1070.67 1080 1070.45 214133 3.57
Json 221 253 224.92 223 224.85 44983 0.75
List 447 497 453.42 452 453.38 90683 1.51
Mandelbrot 140 161 140.6 140 140.59 28121 0.47
NBody 203 318 207.89 205 207.54 41577 0.69
Permute 208 246 211.83 209 211.73 42365 0.71
Queens 175 233 178.9 177 178.82 35779 0.6
Richards 861 903 869.34 865 869.29 173868 2.9
Sieve 208 253 211.23 209 211.08 42245 0.7
Storage 178 280 183.32 180 183.12 36664 0.61
Towers 279 317 280.8 280 280.76 56159 0.94
4454 5211 4586.35 4567 4584.84 917271 15.29
Benchmarks ran on graalvm-ee-java11-21.1.0. 
Runtime:   graalvm-ee-java11-21.1.0
System:    Host: swaarena Kernel: 4.9.0-14-amd64 x86_64 (64 bit) Console: tty 1
         Distro: Debian GNU/Linux 9 (stretch)
Machine:   Device: server System: Dell product: PowerEdge 2950
         Mobo: Dell model: 0H603H v: A05 BIOS: Dell v: 2.5.0 date: 09/12/2008
CPU(s):    2 Quad core Intel Xeon E5410s (-HT-MCP-SMP-) cache: 12288 KB 
         clock speeds: max: 2333 MHz 1: 2333 MHz 2: 2333 MHz 3: 2333 MHz 4: 2333 MHz 5: 2333 MHz 6: 2333 MHz
         7: 2333 MHz 8: 2333 MHz
Memory:    Used/Total: 862.0/32174.3MB
         Array-1 capacity: 63.75 GB devices: 8 EC: Multi-bit ECC
         Device-1: DIMM1 size: 4 GB speed: 667 MHz type: DDR2 FB-DIMM
         Device-2: DIMM2 size: 4 GB speed: 667 MHz type: DDR2 FB-DIMM
         Device-3: DIMM3 size: 4 GB speed: 667 MHz type: DDR2 FB-DIMM
         Device-4: DIMM4 size: 4 GB speed: 667 MHz type: DDR2 FB-DIMM
         Device-5: DIMM5 size: 4 GB speed: 667 MHz type: DDR2 FB-DIMM
         Device-6: DIMM6 size: 4 GB speed: 667 MHz type: DDR2 FB-DIMM
         Device-7: DIMM7 size: 4 GB speed: 667 MHz type: DDR2 FB-DIMM
         Device-8: DIMM8 size: 4 GB speed: 667 MHz type: DDR2 FB-DIMM
Display the source blob
Display the rendered blob
Raw
5d99b29-2-steady.svg
Loading
Sorry, something went wrong. Reload?
Sorry, we cannot display this file.
Sorry, this file is invalid so it cannot be displayed.
Display the source blob
Display the rendered blob
Raw
5d99b29-3-warmup.svg
Loading
Sorry, something went wrong. Reload?
Sorry, we cannot display this file.
Sorry, this file is invalid so it cannot be displayed.
Raw
5d99b29f-Bounce.trace.log
# Bounce (iterations: 250, problem size: 1500) on Thu May 27 21:20:16 UTC 2021
# `/home/fniephaus/bin/graalvm-ee-java11-21.1.0/bin/trufflesqueak --experimental-options --smalltalk.disable-startup --smalltalk.disable-interrupts --engine.Mode=default --engine.MultiTier=false --engine.TraceCompilation --engine.CompilationStatistics --log.file="/home/fniephaus/dev/are-we-fast-yet/traces/Bounce.trace.log" --quiet --code "FileStream startUp: true. Harness new run: #(nil 'Bounce' 250 1500)" /home/fniephaus/dev/are-we-fast-yet/benchmarks/Smalltalk/AWFY64-sista-fbc.image`
[engine] opt done Ball>>bounce |AST 207|Tier 2|Time 319( 266+52 )ms|Inlined 8Y 0N|IR 635/ 792|CodeSize 2521|Addr 0x7f49dea82f10|Src n/a
[engine] opt done Bounce>>benchmark |AST 36|Tier 2|Time 337( 270+67 )ms|Inlined 9Y 0N|IR 770/ 976|CodeSize 3176|Addr 0x7f49dea89190|Src n/a
[engine] opt done Number>>negated |AST 14|Tier 2|Time 55( 52+3 )ms|Inlined 0Y 0N|IR 24/ 91|CodeSize 403|Addr 0x7f49dea91310|Src n/a
[engine] opt done Number>>abs |AST 29|Tier 2|Time 95( 91+4 )ms|Inlined 1Y 0N|IR 61/ 163|CodeSize 572|Addr 0x7f49dea96410|Src n/a
[engine] opt done SomRandom>>next |AST 39|Tier 2|Time 65( 59+5 )ms|Inlined 0Y 0N|IR 83/ 158|CodeSize 527|Addr 0x7f49deaa3590|Src n/a
[engine] opt done SequenceableCollection>>do: <split-2e1792e7> |AST 73|Tier 2|Time 505( 306+198 )ms|Inlined 10Y 0N|IR 938/ 3673|CodeSize 14097|Addr 0x7f49deaa5890|Src n/a
[engine] opt done Behavior>>new <split-4e558728> |AST 26|Tier 2|Time 61( 55+6 )ms|Inlined 0Y 0N|IR 34/ 267|CodeSize 990|Addr 0x7f49deab3890|Src n/a
[engine] opt done Ball class>>new: |AST 31|Tier 2|Time 202( 175+28 )ms|Inlined 6Y 0N|IR 391/ 490|CodeSize 1376|Addr 0x7f49deac2390|Src n/a
[engine] opt done SomRandom>>initialize |AST 10|Tier 2|Time 40( 37+3 )ms|Inlined 0Y 0N|IR 68/ 77|CodeSize 255|Addr 0x7f49deac6590|Src n/a
[engine] opt done Behavior>>new <split-11511459> |AST 28|Tier 2|Time 106( 103+4 )ms|Inlined 1Y 0N|IR 34/ 98|CodeSize 439|Addr 0x7f49deacb810|Src n/a
[engine] opt done SomRandom class>>new |AST 26|Tier 2|Time 119( 115+4 )ms|Inlined 3Y 0N|IR 34/ 98|CodeSize 439|Addr 0x7f49deacbe90|Src n/a
[engine] opt done Bounce>>verifyResult: |AST 15|Tier 2|Time 34( 32+2 )ms|Inlined 0Y 0N|IR 25/ 26|CodeSize 216|Addr 0x7f49deacd290|Src n/a
[engine] opt done Bounce>>benchmark |AST 169|Tier 2|Time 903( 502+401 )ms|Inlined 22Y 0N|IR 1939/ 9164|CodeSize 34256|Addr 0x7f49deacef10|Src n/a
[engine] opt done Benchmark>>innerBenchmarkLoop: |AST 59|Tier 2|Time 959( 441+517 )ms|Inlined 24Y 0N|IR 2031/ 9434|CodeSize 36990|Addr 0x7f49deadf910|Src n/a
[engine] opt done String class>>new: |AST 51|Tier 2|Time 174( 156+18 )ms|Inlined 2Y 1N|IR 213/ 472|CodeSize 1899|Addr 0x7f49deaff110|Src n/a
[engine] opt done SmallInteger>>printString |AST 152|Tier 2|Time 265( 240+25 )ms|Inlined 4Y 1N|IR 361/ 443|CodeSize 1368|Addr 0x7f49deb01890|Src n/a
[engine] opt done SequenceableCollection>>copyReplaceFrom:to:with: |AST 177|Tier 2|Time 275( 235+40 )ms|Inlined 3Y 1N|IR 474/ 1035|CodeSize 4845|Addr 0x7f49deb0c510|Src n/a
[engine] Truffle runtime statistics for engine 2
Compilations : 19
Success : 17
Temporary Bailouts : 0
Permanent Bailouts : 0
Failed : 0
Interrupted : 2
Invalidated : 0
Queues : 19
Dequeues : 1
Target inlined into only caller : 1
Splits : 194
Compilation Accuracy : 1.000000
Queue Accuracy : 0.947368
Compilation Utilization : 0.048767
Remaining Compilation Queue : 0
Time to queue : count= 19, sum= 294408, min= 40, average= 15495.21, max= 93191 (milliseconds), maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Time waiting in queue : count= 19, sum= 1205, min= 1, average= 63.47, max= 269 (milliseconds), maxTarget=Number>>abs
Time for compilation : count= 17, sum= 4560, min= 35, average= 268.26, max= 959 (milliseconds), maxTarget=Benchmark>>innerBenchmarkLoop:
Truffle Tier : count= 17, sum= 3144, min= 32, average= 184.96, max= 502 (milliseconds), maxTarget=Bounce>>benchmark
Graal Tier : count= 17, sum= 1007, min= 1, average= 59.29, max= 383 (milliseconds), maxTarget=Benchmark>>innerBenchmarkLoop:
Code Installation : count= 17, sum= 408, min= 1, average= 24.01, max= 135 (milliseconds), maxTarget=Benchmark>>innerBenchmarkLoop:
Truffle node count : count= 17, sum= 8046, min= 18, average= 473.29, max= 1844, maxTarget=Benchmark>>innerBenchmarkLoop:
Trivial : count= 17, sum= 3119, min= 8, average= 183.47, max= 704, maxTarget=Benchmark>>innerBenchmarkLoop:
Non Trivial : count= 17, sum= 4927, min= 10, average= 289.82, max= 1140, maxTarget=Benchmark>>innerBenchmarkLoop:
Monomorphic : count= 17, sum= 4894, min= 10, average= 287.88, max= 1138, maxTarget=Benchmark>>innerBenchmarkLoop:
Polymorphic : count= 17, sum= 33, min= 0, average= 1.94, max= 11, maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Megamorphic : count= 17, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Ball>>bounce
Truffle call count : count= 17, sum= 96, min= 0, average= 5.65, max= 24, maxTarget=Benchmark>>innerBenchmarkLoop:
Indirect : count= 17, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Ball>>bounce
Direct : count= 17, sum= 96, min= 0, average= 5.65, max= 24, maxTarget=Benchmark>>innerBenchmarkLoop:
Dispatched : count= 17, sum= 3, min= 0, average= 0.18, max= 1, maxTarget=String class>>new:
Inlined : count= 17, sum= 93, min= 0, average= 5.47, max= 24, maxTarget=Benchmark>>innerBenchmarkLoop:
---------- :
Cloned : count= 17, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Ball>>bounce
Not Cloned : count= 17, sum= 96, min= 0, average= 5.65, max= 24, maxTarget=Benchmark>>innerBenchmarkLoop:
Truffle loops : count= 17, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Ball>>bounce
Graal node count :
After Truffle Tier : count= 17, sum= 8115, min= 24, average= 477.35, max= 2031, maxTarget=Benchmark>>innerBenchmarkLoop:
After Graal Tier : count= 17, sum= 27457, min= 26, average= 1615.12, max= 9434, maxTarget=Benchmark>>innerBenchmarkLoop:
Graal compilation result :
Code size : count= 17, sum= 104369, min= 216, average= 6139.35, max= 36990, maxTarget=Benchmark>>innerBenchmarkLoop:
Total frame size : count= 17, sum= 2256, min= 32, average= 132.71, max= 624, maxTarget=Benchmark>>innerBenchmarkLoop:
Exception handlers : count= 17, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Ball>>bounce
Infopoints : count= 17, sum= 997, min= 4, average= 58.65, max= 308, maxTarget=Benchmark>>innerBenchmarkLoop:
CALL : count= 17, sum= 787, min= 4, average= 46.29, max= 242, maxTarget=Benchmark>>innerBenchmarkLoop:
IMPLICIT_EXCEPTION : count= 17, sum= 191, min= 0, average= 11.24, max= 59, maxTarget=Benchmark>>innerBenchmarkLoop:
SAFEPOINT : count= 17, sum= 19, min= 0, average= 1.12, max= 7, maxTarget=Benchmark>>innerBenchmarkLoop:
Marks : count= 17, sum= 152, min= 7, average= 8.94, max= 15, maxTarget=Ball>>bounce
Data references : count= 17, sum= 779, min= 2, average= 45.82, max= 252, maxTarget=Bounce>>benchmark
Raw
5d99b29f-DeltaBlue.trace.log
# DeltaBlue (iterations: 250, problem size: 12000) on Thu May 27 21:27:09 UTC 2021
# `/home/fniephaus/bin/graalvm-ee-java11-21.1.0/bin/trufflesqueak --experimental-options --smalltalk.disable-startup --smalltalk.disable-interrupts --engine.Mode=default --engine.MultiTier=false --engine.TraceCompilation --engine.CompilationStatistics --log.file="/home/fniephaus/dev/are-we-fast-yet/traces/DeltaBlue.trace.log" --quiet --code "FileStream startUp: true. Harness new run: #(nil 'DeltaBlue' 250 12000)" /home/fniephaus/dev/are-we-fast-yet/benchmarks/Smalltalk/AWFY64-sista-fbc.image`
[engine] opt done Behavior>>new <split-3aefae67> |AST 26|Tier 2|Time 170( 136+34 )ms|Inlined 0Y 0N|IR 33/ 97|CodeSize 433|Addr 0x7f31470dad10|Src n/a
[engine] opt done Vector>>initialize: |AST 30|Tier 2|Time 171( 146+26 )ms|Inlined 0Y 0N|IR 139/ 337|CodeSize 959|Addr 0x7f31470dce90|Src n/a
[engine] opt done Vector class>>new: |AST 29|Tier 2|Time 200( 188+12 )ms|Inlined 2Y 0N|IR 57/ 364|CodeSize 1232|Addr 0x7f31470e0d10|Src n/a
[engine] opt done Strength class>>absoluteWeakest |AST 10|Tier 2|Time 34( 33+2 )ms|Inlined 0Y 0N|IR 21/ 27|CodeSize 230|Addr 0x7f31470e5c90|Src n/a
[engine] opt done Vector>>isEmpty |AST 18|Tier 2|Time 45( 42+3 )ms|Inlined 0Y 0N|IR 31/ 46|CodeSize 276|Addr 0x7f3147111a90|Src n/a
[engine] opt done BinaryConstraint>>output |AST 20|Tier 2|Time 79( 70+9 )ms|Inlined 0Y 0N|IR 37/ 64|CodeSize 401|Addr 0x7f3147119410|Src n/a
[engine] opt done Vector>>append: |AST 60|Tier 2|Time 133( 116+17 )ms|Inlined 0Y 0N|IR 223/ 701|CodeSize 2109|Addr 0x7f3147121d10|Src n/a
[engine] opt done Vector>>forEach: <split-6999cd39> |AST 79|Tier 2|Time 167( 136+31 )ms|Inlined 1Y 0N|IR 201/ 1279|CodeSize 4349|Addr 0x7f3147135390|Src n/a
[engine] opt done Variable>>addConstraint: |AST 24|Tier 2|Time 138( 115+22 )ms|Inlined 1Y 0N|IR 289/ 766|CodeSize 2291|Addr 0x7f3147137590|Src n/a
[engine] opt done Variable>>mark: |AST 11|Tier 2|Time 34( 31+3 )ms|Inlined 0Y 0N|IR 73/ 88|CodeSize 273|Addr 0x7f3147141890|Src n/a
[engine] opt done Strength>>weaker: |AST 27|Tier 2|Time 51( 48+3 )ms|Inlined 0Y 0N|IR 39/ 62|CodeSize 312|Addr 0x7f3147144d10|Src n/a
[engine] opt done Integer>>>> |AST 31|Tier 2|Time 48( 45+3 )ms|Inlined 0Y 0N|IR 39/ 111|CodeSize 462|Addr 0x7f314714c510|Src n/a
[engine] opt done SomDictionary>>hash: |AST 60|Tier 2|Time 82( 78+4 )ms|Inlined 1Y 0N|IR 33/ 106|CodeSize 436|Addr 0x7f314714f410|Src n/a
[engine] opt done SomDictionary>>bucketIdx: |AST 40|Tier 2|Time 69( 63+6 )ms|Inlined 0Y 0N|IR 91/ 211|CodeSize 770|Addr 0x7f3147158710|Src n/a
[engine] opt done SomDictionary>>bucket: |AST 33|Tier 2|Time 139( 134+5 )ms|Inlined 1Y 0N|IR 155/ 115|CodeSize 599|Addr 0x7f3147163b90|Src n/a
[engine] opt done Planner>>addPropagate:mark: |AST 131|Tier 2|Time 561( 433+128 )ms|Inlined 22Y 0N|IR 873/ 1183|CodeSize 4259|Addr 0x7f3147166510|Src n/a
[engine] opt done SomDictionary>>at: |AST 86|Tier 2|Time 214( 207+7 )ms|Inlined 5Y 0N|IR 238/ 189|CodeSize 867|Addr 0x7f314716ad90|Src n/a
[engine] opt done Strength class>>SymRequired |AST 10|Tier 2|Time 30( 28+2 )ms|Inlined 0Y 0N|IR 21/ 27|CodeSize 230|Addr 0x7f314716d210|Src n/a
[engine] opt done Behavior>>new <split-6fe46b62> |AST 26|Tier 2|Time 51( 45+5 )ms|Inlined 0Y 0N|IR 92/ 268|CodeSize 988|Addr 0x7f3147176110|Src n/a
[engine] opt done Strength class>>of: |AST 23|Tier 2|Time 165( 158+7 )ms|Inlined 6Y 0N|IR 285/ 204|CodeSize 929|Addr 0x7f3147176990|Src n/a
[engine] opt deopt Vector>>forEach: <split-6999cd39> |AST 79|Src n/a
[engine] opt inv. Planner>>addPropagate:mark: |AST 143|Calls/Thres 6679/ 3|CallsAndLoop/Thres 13359/ 1000|Src n/a|Reason validRootAssumption Split call node
[engine] opt inv. Vector>>forEach: <split-6999cd39> |AST 79|Calls/Thres 2397/ 3|CallsAndLoop/Thres 4795/ 1000|Src n/a|Reason validRootAssumption Split call node
[engine] opt done BinaryConstraint>>initializeVar:var:strength:addTo: |AST 34|Tier 2|Time 180( 177+3 )ms|Inlined 8Y 0N|IR 353/ 5|CodeSize 120|Addr 0x7f314717f390|Src n/a
[engine] opt done Vector class>>with: |AST 43|Tier 2|Time 141( 134+7 )ms|Inlined 4Y 0N|IR 147/ 394|CodeSize 1353|Addr 0x7f3147186990|Src n/a
[engine] opt done Vector>>removeFirst |AST 53|Tier 2|Time 207( 201+5 )ms|Inlined 1Y 0N|IR 124/ 164|CodeSize 656|Addr 0x7f3147187710|Src n/a
[engine] opt done Variable>>walkStrength: |AST 11|Tier 2|Time 29( 26+3 )ms|Inlined 0Y 0N|IR 60/ 165|CodeSize 445|Addr 0x7f3147189390|Src n/a
[engine] opt done Variable>>stay: |AST 11|Tier 2|Time 29( 27+3 )ms|Inlined 0Y 0N|IR 76/ 91|CodeSize 273|Addr 0x7f314718b190|Src n/a
[engine] opt done Planner>>addConstraintsConsuming:to: |AST 57|Tier 2|Time 151( 128+24 )ms|Inlined 3Y 0N|IR 310/ 446|CodeSize 1731|Addr 0x7f314718e610|Src n/a
[engine] opt done BinaryConstraint>>recalculate |AST 147|Tier 2|Time 168( 150+18 )ms|Inlined 9Y 0N|IR 607/ 529|CodeSize 1572|Addr 0x7f3147196390|Src n/a
[engine] opt done Symbol>>= <split-585ac855> |AST 28|Tier 2|Time 40( 37+3 )ms|Inlined 0Y 0N|IR 58/ 73|CodeSize 298|Addr 0x7f3147197d90|Src n/a
[engine] opt done Strength>>weakest: |AST 25|Tier 2|Time 53( 50+3 )ms|Inlined 1Y 0N|IR 41/ 63|CodeSize 287|Addr 0x7f3147198390|Src n/a
[engine] opt deopt Planner>>addConstraintsConsuming:to: |AST 57|Src n/a
[engine] opt inv. Planner>>addConstraintsConsuming:to: |AST 57|Calls/Thres 20927/ 3|CallsAndLoop/Thres 20927/ 1000|Src n/a|Reason validRootAssumption Split call node
[engine] opt inv. Vector class>>with: |AST 43|Calls/Thres 12956/ 3|CallsAndLoop/Thres 12956/ 1000|Src n/a|Reason frame version
[engine] opt inv. Variable>>addConstraint: |AST 24|Calls/Thres 4890/ 3|CallsAndLoop/Thres 4890/ 1000|Src n/a|Reason frame version
[engine] opt inv. Vector>>append: |AST 124|Calls/Thres 3370/ 3|CallsAndLoop/Thres 3370/ 1000|Src n/a|Reason frame version
[engine] opt done EqualityConstraint>>execute |AST 80|Tier 2|Time 89( 83+6 )ms|Inlined 3Y 0N|IR 281/ 164|CodeSize 644|Addr 0x7f314719fa10|Src n/a
[engine] opt done Vector>>forEach: <split-6999cd39> |AST 79|Tier 2|Time 469( 320+149 )ms|Inlined 3Y 0N|IR 940/ 3920|CodeSize 15861|Addr 0x7f31471a4510|Src n/a
[engine] opt done Vector>>forEach: <split-5f462e3b> |AST 79|Tier 2|Time 194( 124+70 )ms|Inlined 5Y 0N|IR 549/ 3057|CodeSize 11633|Addr 0x7f31471ad090|Src n/a
[engine] opt inv. Vector>>isEmpty |AST 18|Calls/Thres 1850/ 3|CallsAndLoop/Thres 1850/ 1000|Src n/a|Reason Profiled Argument Types
[engine] opt inv. Vector>>removeFirst |AST 53|Calls/Thres 16541/ 3|CallsAndLoop/Thres 16541/ 1000|Src n/a|Reason Profiled Argument Types
[engine] opt done Plan>>execute |AST 20|Tier 2|Time 97( 88+9 )ms|Inlined 4Y 0N|IR 364/ 244|CodeSize 821|Addr 0x7f31471b7d10|Src n/a
[engine] opt done Vector>>removeFirst |AST 53|Tier 2|Time 80( 74+5 )ms|Inlined 1Y 0N|IR 123/ 164|CodeSize 656|Addr 0x7f31471bc190|Src n/a
[engine] opt done Planner>>addConstraintsConsuming:to: |AST 57|Tier 2|Time 379( 209+170 )ms|Inlined 4Y 0N|IR 1099/ 2304|CodeSize 10320|Addr 0x7f31471bcb10|Src n/a
[engine] opt inv. Vector class>>new: |AST 29|Calls/Thres 8817/ 3|CallsAndLoop/Thres 8817/ 1000|Src n/a
[engine] opt done Vector class>>new: |AST 29|Tier 2|Time 199( 186+13 )ms|Inlined 2Y 0N|IR 137/ 460|CodeSize 1363|Addr 0x7f31471c7690|Src n/a
[engine] opt done Symbol>>= <split-54dcbb9f> |AST 28|Tier 2|Time 43( 40+3 )ms|Inlined 0Y 0N|IR 58/ 73|CodeSize 298|Addr 0x7f31471c8510|Src n/a
[engine] opt done Symbol>>= <split-4d8539de> |AST 28|Tier 2|Time 43( 40+3 )ms|Inlined 0Y 0N|IR 58/ 73|CodeSize 298|Addr 0x7f31471c8b10|Src n/a
[engine] opt done Vector class>>with: |AST 43|Tier 2|Time 285( 275+9 )ms|Inlined 4Y 0N|IR 281/ 394|CodeSize 1353|Addr 0x7f31471c9410|Src n/a
[engine] opt done Variable>>value: |AST 11|Tier 2|Time 31( 29+3 )ms|Inlined 0Y 0N|IR 74/ 88|CodeSize 273|Addr 0x7f31471c9f10|Src n/a
[engine] opt inv. Vector>>initialize: |AST 30|Calls/Thres 7306/ 3|CallsAndLoop/Thres 7306/ 1000|Src n/a
[engine] opt done Vector>>initialize: |AST 30|Tier 2|Time 68( 59+9 )ms|Inlined 0Y 0N|IR 139/ 337|CodeSize 959|Addr 0x7f31471ca590|Src n/a
[engine] opt inv. Behavior>>new <split-3aefae67> |AST 27|Calls/Thres 6371/ 3|CallsAndLoop/Thres 6371/ 1000|Src n/a
[engine] opt done Behavior>>new <split-3aefae67> |AST 27|Tier 2|Time 55( 49+6 )ms|Inlined 0Y 0N|IR 80/ 141|CodeSize 502|Addr 0x7f31471cb110|Src n/a
[engine] opt done Vector>>isEmpty |AST 18|Tier 2|Time 38( 36+2 )ms|Inlined 0Y 0N|IR 31/ 46|CodeSize 276|Addr 0x7f31471cb890|Src n/a
[engine] opt inv. BinaryConstraint>>output |AST 26|Calls/Thres 138443/ 3|CallsAndLoop/Thres 138446/ 1000|Src n/a
[engine] opt done BinaryConstraint>>output |AST 26|Tier 2|Time 44( 39+5 )ms|Inlined 0Y 0N|IR 64/ 94|CodeSize 449|Addr 0x7f31471cd010|Src n/a
[engine] opt done Vector>>append: |AST 124|Tier 2|Time 193( 129+64 )ms|Inlined 0Y 0N|IR 638/ 2330|CodeSize 9585|Addr 0x7f31471cda10|Src n/a
[engine] opt done Vector>>forEach: <split-3d7fa3ae> |AST 79|Tier 2|Time 326( 185+142 )ms|Inlined 3Y 0N|IR 1002/ 3995|CodeSize 16614|Addr 0x7f31471d5610|Src n/a
[engine] opt inv. BinaryConstraint>>output |AST 26|Calls/Thres 140938/ 3|CallsAndLoop/Thres 140938/ 1000|Src n/a
[engine] opt done BinaryConstraint>>output |AST 26|Tier 2|Time 41( 36+6 )ms|Inlined 0Y 0N|IR 95/ 141|CodeSize 550|Addr 0x7f31471ddb90|Src n/a
[engine] opt done Variable>>initialize |AST 56|Tier 2|Time 118( 105+12 )ms|Inlined 4Y 0N|IR 310/ 710|CodeSize 1994|Addr 0x7f31471e2710|Src n/a
[engine] opt done Vector>>forEach: <split-58065f0c> |AST 79|Tier 2|Time 659( 310+349 )ms|Inlined 15Y 0N|IR 1799/ 5704|CodeSize 21578|Addr 0x7f31471e3c90|Src n/a
[engine] opt done Variable class>>new |AST 26|Tier 2|Time 183( 160+23 )ms|Inlined 11Y 0N|IR 551/ 1231|CodeSize 3876|Addr 0x7f31471f1090|Src n/a
[engine] opt done Planner>>addPropagate:mark: <split-378bd86d> |AST 131|Tier 2|Time 858( 575+283 )ms|Inlined 25Y 0N|IR 2235/ 3030|CodeSize 13566|Addr 0x7f31471f3c90|Src n/a
[engine] opt done Behavior>>new <split-6bff19ff> |AST 28|Tier 2|Time 120( 111+10 )ms|Inlined 5Y 0N|IR 265/ 586|CodeSize 1715|Addr 0x7f3147200c90|Src n/a
[engine] opt inv. BinaryConstraint>>initializeVar:var:strength:addTo: |AST 34|Calls/Thres 19133/ 3|CallsAndLoop/Thres 19133/ 1000|Src n/a
[engine] opt done BinaryConstraint>>initializeVar:var:strength:addTo: |AST 34|Tier 2|Time 191( 175+16 )ms|Inlined 8Y 0N|IR 505/ 844|CodeSize 2591|Addr 0x7f3147202190|Src n/a
[engine] opt done Variable>>addConstraint: |AST 24|Tier 2|Time 247( 140+107 )ms|Inlined 1Y 0N|IR 738/ 3318|CodeSize 11251|Addr 0x7f3147203890|Src n/a
[engine] opt deopt Vector>>forEach: <split-5f462e3b> |AST 79|Src n/a
[engine] opt deopt Vector>>forEach: <split-3d7fa3ae> |AST 79|Src n/a
[engine] opt deopt Vector>>forEach: <split-58065f0c> |AST 79|Src n/a
[engine] opt deopt BinaryConstraint>>output |AST 26|Src n/a
[engine] opt inv. BinaryConstraint>>output |AST 26|Calls/Thres 142557/ 3|CallsAndLoop/Thres 142557/ 1000|Src n/a
[engine] opt done BinaryConstraint>>output |AST 26|Tier 2|Time 41( 35+6 )ms|Inlined 0Y 0N|IR 100/ 145|CodeSize 557|Addr 0x7f314720d710|Src n/a
[engine] opt done Planner>>addPropagate:mark: <split-7c8326a4> |AST 135|Tier 2|Time 657( 581+77 )ms|Inlined 24Y 0N|IR 1418/ 1143|CodeSize 3592|Addr 0x7f314720e390|Src n/a
[engine] opt inv. Vector>>forEach: <split-3d7fa3ae> |AST 79|Calls/Thres 12004/ 3|CallsAndLoop/Thres 36010/ 1000|Src n/a
[engine] opt done Vector>>forEach: <split-3d7fa3ae> |AST 79|Tier 2|Time 325( 176+148 )ms|Inlined 3Y 0N|IR 1077/ 4099|CodeSize 16449|Addr 0x7f3147212990|Src n/a
[engine] opt done Planner>>removePropagateFrom: |AST 41|Tier 2|Time 212( 148+64 )ms|Inlined 2Y 0N|IR 867/ 1834|CodeSize 8219|Addr 0x7f314721df10|Src n/a
[engine] opt done BinaryConstraint>>isSatisfied <split-585c13de> |AST 17|Tier 2|Time 38( 34+4 )ms|Inlined 0Y 0N|IR 75/ 112|CodeSize 438|Addr 0x7f3147223090|Src n/a
[engine] opt inv. Vector>>forEach: <split-58065f0c> |AST 79|Calls/Thres 12004/ 3|CallsAndLoop/Thres 36010/ 1000|Src n/a
[engine] opt done Vector>>forEach: <split-58065f0c> |AST 79|Tier 2|Time 888( 449+439 )ms|Inlined 25Y 0N|IR 2712/ 6538|CodeSize 24516|Addr 0x7f3147223810|Src n/a
[engine] opt done Symbol>>= <split-2adddc06> |AST 28|Tier 2|Time 42( 39+3 )ms|Inlined 0Y 0N|IR 58/ 44|CodeSize 326|Addr 0x7f3147234890|Src n/a
[engine] opt done Vector>>forEach: <split-38499e48> |AST 79|Tier 2|Time 224( 151+73 )ms|Inlined 5Y 0N|IR 657/ 2750|CodeSize 11006|Addr 0x7f3147235390|Src n/a
[engine] opt done Plan>>execute <split-4a699efa> |AST 20|Tier 2|Time 122( 111+12 )ms|Inlined 4Y 0N|IR 473/ 398|CodeSize 1482|Addr 0x7f314723cd10|Src n/a
[engine] opt done Planner>>constraintsConsuming:do: |AST 62|Tier 2|Time 679( 486+193 )ms|Inlined 24Y 0N|IR 2473/ 4116|CodeSize 17138|Addr 0x7f314723dd10|Src n/a
[engine] opt done Vector>>forEach: <split-c3fa05a> |AST 79|Tier 2|Time 331( 188+143 )ms|Inlined 3Y 0N|IR 1054/ 3824|CodeSize 15358|Addr 0x7f314724ab10|Src n/a
[engine] opt done Vector>>forEach: <split-17ae7628> |AST 79|Tier 2|Time 297( 119+179 )ms|Inlined 1Y 0N|IR 396/ 3529|CodeSize 13138|Addr 0x7f3147255a10|Src n/a
[engine] opt done Symbol>>= <split-2d7e1102> |AST 28|Tier 2|Time 40( 38+3 )ms|Inlined 0Y 0N|IR 58/ 44|CodeSize 326|Addr 0x7f314725b190|Src n/a
[engine] opt done Vector>>forEach: <split-6ac97b84> |AST 79|Tier 2|Time 328( 190+138 )ms|Inlined 3Y 0N|IR 1072/ 3893|CodeSize 15078|Addr 0x7f314725f290|Src n/a
[engine] opt done Planner>>makePlan: |AST 212|Tier 2|Time 1030( 618+412 )ms|Inlined 24Y 0N|IR 2802/ 5081|CodeSize 27133|Addr 0x7f314726c290|Src n/a
[engine] opt done Vector>>forEach: <split-66434cc8> |AST 79|Tier 2|Time 434( 177+256 )ms|Inlined 3Y 0N|IR 941/ 3920|CodeSize 15308|Addr 0x7f314727e790|Src n/a
[engine] opt deopt Vector>>forEach: <split-c3fa05a> |AST 79|Src n/a
[engine] opt deopt Planner>>makePlan: |AST 212|Src n/a
[engine] opt done Planner>>removePropagateFrom: |AST 211|Tier 2|Time 2622( 970+1653)ms|Inlined 50Y 0N|IR 5815/21473|CodeSize 84366|Addr 0x7f3147291c10|Src n/a
[engine] opt inv. Vector>>forEach: <split-c3fa05a> |AST 79|Calls/Thres 24004/ 3|CallsAndLoop/Thres 72014/ 1000|Src n/a
[engine] opt done Vector>>forEach: <split-c3fa05a> |AST 79|Tier 2|Time 485( 322+163 )ms|Inlined 3Y 0N|IR 1128/ 4007|CodeSize 16197|Addr 0x7f31472c7290|Src n/a
[engine] opt done EqualityConstraint>>initializeVar:var:strength:addTo: |AST 45|Tier 2|Time 2015(1088+927 )ms|Inlined 57Y 0N|IR 4712/ 9798|CodeSize 35008|Addr 0x7f31472d0510|Src n/a
[engine] opt done AbstractConstraint>>inputsKnown: |AST 37|Tier 2|Time 137( 123+14 )ms|Inlined 5Y 0N|IR 350/ 340|CodeSize 1018|Addr 0x7f31472f2210|Src n/a
[engine] opt done Symbol>>= <split-70325d20> |AST 28|Tier 2|Time 41( 38+3 )ms|Inlined 0Y 0N|IR 58/ 44|CodeSize 326|Addr 0x7f31472f3b90|Src n/a
[engine] opt done BinaryConstraint>>inputsHasOne: |AST 59|Tier 2|Time 134( 98+37 )ms|Inlined 3Y 0N|IR 397/ 2273|CodeSize 7176|Addr 0x7f31472f4090|Src n/a
[engine] opt done Planner>>addConstraintsConsuming:to: <split-35c09b94> |AST 61|Tier 2|Time 225( 159+66 )ms|Inlined 2Y 0N|IR 916/ 1843|CodeSize 7967|Addr 0x7f31472f7210|Src n/a
[engine] opt done Planner>>addConstraintsConsuming:to: <split-7b44b63d> |AST 57|Tier 2|Time 475( 209+265 )ms|Inlined 4Y 0N|IR 1174/ 2342|CodeSize 9885|Addr 0x7f31472fc090|Src n/a
[engine] opt done Vector>>forEach: <split-16fe9c29> |AST 79|Tier 2|Time 295( 222+73 )ms|Inlined 5Y 0N|IR 549/ 3057|CodeSize 11632|Addr 0x7f3147304f10|Src n/a
[engine] opt done BinaryConstraint>>isSatisfied <split-2d0bfb24> |AST 17|Tier 2|Time 54( 49+5 )ms|Inlined 0Y 0N|IR 75/ 112|CodeSize 438|Addr 0x7f3147313d10|Src n/a
[engine] opt done BinaryConstraint>>isSatisfied <split-6ad11a56> |AST 17|Tier 2|Time 48( 44+4 )ms|Inlined 0Y 0N|IR 75/ 112|CodeSize 438|Addr 0x7f3147314490|Src n/a
[engine] opt done Plan>>execute <split-2e52fb3e> |AST 20|Tier 2|Time 107( 98+9 )ms|Inlined 4Y 0N|IR 364/ 244|CodeSize 821|Addr 0x7f3147314c10|Src n/a
[engine] opt done Planner>>incrementalAdd: <split-72ba28ee> |AST 72|Tier 2|Time 3324(1575+1749)ms|Inlined 78Y 3N|IR 7739/18174|CodeSize 71278|Addr 0x7f3147315890|Src n/a
[engine] opt done Planner>>removePropagateFrom: |AST 49|Tier 2|Time 551( 420+132 )ms|Inlined 22Y 0N|IR 2166/ 3044|CodeSize 11562|Addr 0x7f3147346e10|Src n/a
[engine] opt deopt Vector>>forEach: <split-66434cc8> |AST 79|Src n/a
[engine] opt done EqualityConstraint class>>var:var:strength:addTo: |AST 40|Tier 2|Time 2219(1099+1120)ms|Inlined 59Y 0N|IR 4696/10037|CodeSize 38433|Addr 0x7f3147353d10|Src n/a
[engine] opt done Planner>>incrementalAdd: <split-7808fb9> |AST 72|Tier 2|Time 1769(1173+596 )ms|Inlined 66Y 0N|IR 4180/ 5131|CodeSize 20889|Addr 0x7f314737e210|Src n/a
[engine] opt done StayConstraint class>>var:strength:addTo: |AST 37|Tier 2|Time 2817(1491+1326)ms|Inlined 79Y 2N|IR 6182/10805|CodeSize 42745|Addr 0x7f3147398210|Src n/a
[engine] opt done Vector>>forEach: <split-5cbb84b1> |AST 79|Tier 2|Time 139( 96+43 )ms|Inlined 2Y 0N|IR 246/ 2170|CodeSize 7900|Addr 0x7f31473c1a10|Src n/a
[engine] opt inv. Planner>>makePlan: |AST 212|Calls/Thres 10/ 3|CallsAndLoop/Thres 84025/ 1000|Src n/a
[engine] opt done Planner>>makePlan: |AST 212|Tier 2|Time 1104( 516+588 )ms|Inlined 24Y 0N|IR 2873/ 5398|CodeSize 29162|Addr 0x7f31473c4f10|Src n/a
[engine] opt inv. Vector>>forEach: <split-66434cc8> |AST 79|Calls/Thres 12003/ 3|CallsAndLoop/Thres 36010/ 1000|Src n/a
[engine] opt done Vector>>forEach: <split-66434cc8> |AST 79|Tier 2|Time 330( 186+144 )ms|Inlined 3Y 0N|IR 1121/ 3877|CodeSize 16052|Addr 0x7f31473d9590|Src n/a
[engine] opt done Planner>>addPropagate:mark: <split-6a84bc2a> |AST 131|Tier 2|Time 620( 428+193 )ms|Inlined 24Y 0N|IR 1428/ 1143|CodeSize 3592|Addr 0x7f31473e5790|Src n/a
[engine] opt done Planner>>addConstraintsConsuming:to: <split-2c779e5> |AST 41|Tier 2|Time 60( 57+4 )ms|Inlined 1Y 0N|IR 77/ 120|CodeSize 417|Addr 0x7f31473e9e10|Src n/a
[engine] opt done Planner>>addConstraintsConsuming:to: <split-6579c3d9> |AST 61|Tier 2|Time 219( 157+62 )ms|Inlined 2Y 0N|IR 923/ 1827|CodeSize 7792|Addr 0x7f31473f1290|Src n/a
[engine] opt done AbstractConstraint>>satisfy:propagate: <split-5183d589> |AST 165|Tier 2|Time 972( 800+172 )ms|Inlined 41Y 0N|IR 2808/ 2937|CodeSize 10915|Addr 0x7f31473f8f10|Src n/a
[engine] opt done Strength class>>SymDefault |AST 10|Tier 2|Time 25( 23+2 )ms|Inlined 0Y 0N|IR 21/ 27|CodeSize 230|Addr 0x7f3147404310|Src n/a
[engine] opt done Planner class>>chainTest: |AST 461|Tier 2|Time 3964(2201+1764)ms|Inlined 71Y 5N|IR 5190/15714|CodeSize 64210|Addr 0x7f3147404a90|Src n/a
[engine] opt done Behavior>>new <split-4565a70a> |AST 26|Tier 2|Time 48( 42+5 )ms|Inlined 0Y 0N|IR 92/ 276|CodeSize 1016|Addr 0x7f314743c210|Src n/a
[engine] opt done Planner>>incrementalAdd: <split-33db28fa> |AST 72|Tier 2|Time 2149(1284+865 )ms|Inlined 71Y 0N|IR 4947/ 8204|CodeSize 33062|Addr 0x7f314743de10|Src n/a
[engine] opt done AbstractConstraint>>satisfy:propagate: <split-48bfb884> |AST 212|Tier 2|Time 1077( 847+230 )ms|Inlined 46Y 0N|IR 3516/ 5103|CodeSize 19232|Addr 0x7f3147457c10|Src n/a
[engine] opt done ScaleConstraint>>initializeSrc:scale:offset:dst:strength:addTo:|AST 55|Tier 2|Time 3053(1294+1759)ms|Inlined 62Y 4N|IR 7601/18842|CodeSize 78766|Addr 0x7f3147468e10|Src n/a
[engine] opt done ScaleConstraint class>>var:var:var:var:strength:addTo: |AST 46|Tier 2|Time 3650(1508+2142)ms|Inlined 64Y 4N|IR 7582/18896|CodeSize 79892|Addr 0x7f31474a1910|Src n/a
[engine] opt done Vector>>forEach: <split-68e62ca4> |AST 79|Tier 2|Time 148( 97+50 )ms|Inlined 2Y 0N|IR 324/ 2396|CodeSize 8984|Addr 0x7f31474e2a90|Src n/a
[engine] opt done Planner>>addConstraintsConsuming:to: <split-5328a9c1> |AST 45|Tier 2|Time 66( 61+5 )ms|Inlined 1Y 0N|IR 136/ 159|CodeSize 555|Addr 0x7f31474e6910|Src n/a
[engine] opt done BinaryConstraint>>isSatisfied <split-11653e3b> |AST 17|Tier 2|Time 37( 35+3 )ms|Inlined 0Y 0N|IR 32/ 54|CodeSize 356|Addr 0x7f31474e7210|Src n/a
[engine] opt done Planner>>addConstraintsConsuming:to: <split-715fb77> |AST 57|Tier 2|Time 362( 333+28 )ms|Inlined 3Y 0N|IR 388/ 548|CodeSize 2099|Addr 0x7f31474e7790|Src n/a
[engine] opt done BinaryConstraint>>isSatisfied <split-1b9c1b51> |AST 17|Tier 2|Time 35( 33+2 )ms|Inlined 0Y 0N|IR 28/ 40|CodeSize 252|Addr 0x7f31474ea110|Src n/a
[engine] opt done Planner>>addPropagate:mark: <split-5b78fdb1> |AST 131|Tier 2|Time 708( 626+82 )ms|Inlined 24Y 0N|IR 1505/ 1244|CodeSize 3874|Addr 0x7f31474ea610|Src n/a
[engine] opt done Planner>>addPropagate:mark: <split-baf1bb3> |AST 143|Tier 2|Time 1060( 558+503 )ms|Inlined 28Y 0N|IR 2668/ 4308|CodeSize 20599|Addr 0x7f31474efa10|Src n/a
[engine] opt done Symbol>>= <split-466d49f0> |AST 28|Tier 2|Time 39( 36+3 )ms|Inlined 0Y 0N|IR 58/ 44|CodeSize 326|Addr 0x7f31474fd590|Src n/a
[engine] opt done Planner>>addPropagate:mark: <split-67ec8477> |AST 143|Tier 2|Time 1051( 709+342 )ms|Inlined 28Y 0N|IR 2668/ 4308|CodeSize 20599|Addr 0x7f31474fda90|Src n/a
[engine] opt done Planner class>>projectionTest: |AST 527|Tier 2|Time 2970(2015+955 )ms|Inlined 81Y 6N|IR 3822/17235|CodeSize 72954|Addr 0x7f314750b610|Src n/a
[engine] opt done Vector>>forEach: <split-286b39c2> |AST 79|Tier 2|Time 114( 85+29 )ms|Inlined 1Y 0N|IR 201/ 1279|CodeSize 4349|Addr 0x7f3147533f10|Src n/a
[engine] opt done Planner>>addPropagate:mark: <split-693e4d19> |AST 131|Tier 2|Time 496( 409+87 )ms|Inlined 23Y 0N|IR 1350/ 1332|CodeSize 4437|Addr 0x7f3147536110|Src n/a
[engine] opt done Vector>>forEach: <split-732bb66d> |AST 79|Tier 2|Time 116( 87+29 )ms|Inlined 1Y 0N|IR 201/ 1279|CodeSize 4382|Addr 0x7f314753b010|Src n/a
[engine] opt done Planner>>addPropagate:mark: <split-61533ae> |AST 131|Tier 2|Time 636( 532+104 )ms|Inlined 23Y 0N|IR 1502/ 1546|CodeSize 5173|Addr 0x7f314753e310|Src n/a
[engine] opt done Planner>>incrementalAdd: <split-7c28c1> |AST 72|Tier 2|Time 1760(1151+609 )ms|Inlined 66Y 0N|IR 4175/ 4878|CodeSize 20987|Addr 0x7f3147543090|Src n/a
[engine] opt done ScaleConstraint>>addToGraph |AST 78|Tier 2|Time 1009( 318+691 )ms|Inlined 8Y 0N|IR 2804/12974|CodeSize 45240|Addr 0x7f3147559590|Src n/a
[engine] opt done Vector>>forEach: <split-3e9803c2> |AST 79|Tier 2|Time 141( 97+43 )ms|Inlined 2Y 0N|IR 246/ 2170|CodeSize 7900|Addr 0x7f3147574a90|Src n/a
[engine] opt done AbstractConstraint>>satisfy:propagate: <split-1eea9d2d> |AST 165|Tier 2|Time 960( 669+290 )ms|Inlined 41Y 0N|IR 2808/ 2937|CodeSize 10863|Addr 0x7f3147577f90|Src n/a
[engine] opt done Planner>>addConstraintsConsuming:to: <split-4525d1d3> |AST 41|Tier 2|Time 59( 55+4 )ms|Inlined 1Y 0N|IR 77/ 120|CodeSize 417|Addr 0x7f3147581f10|Src n/a
[engine] opt done BinaryConstraint>>isSatisfied <split-60921b21> |AST 17|Tier 2|Time 36( 33+3 )ms|Inlined 0Y 0N|IR 32/ 54|CodeSize 356|Addr 0x7f3147582610|Src n/a
[engine] opt done Planner>>addPropagate:mark: <split-7c974942> |AST 131|Tier 2|Time 610( 535+75 )ms|Inlined 24Y 0N|IR 1428/ 1143|CodeSize 3592|Addr 0x7f3147584c90|Src n/a
[engine] opt done Planner>>addConstraintsConsuming:to: <split-bd2f5a9> |AST 57|Tier 2|Time 158( 133+25 )ms|Inlined 3Y 0N|IR 310/ 446|CodeSize 1731|Addr 0x7f3147589010|Src n/a
[engine] opt done BinaryConstraint>>isSatisfied <split-4d4960c8> |AST 17|Tier 2|Time 38( 35+2 )ms|Inlined 0Y 0N|IR 28/ 40|CodeSize 252|Addr 0x7f314758b210|Src n/a
[engine] opt done AbstractConstraint>>addConstraint: <split-15723761> |AST 35|Tier 2|Time 2482(1117+1365)ms|Inlined 52Y 4N|IR 7044/18018|CodeSize 76029|Addr 0x7f314758b710|Src n/a
[engine] opt done BinaryConstraint>>isSatisfied <split-3fbfa96> |AST 17|Tier 2|Time 38( 35+3 )ms|Inlined 0Y 0N|IR 32/ 54|CodeSize 356|Addr 0x7f31475bd290|Src n/a
[engine] opt done Planner>>addConstraintsConsuming:to: <split-301d8120> |AST 57|Tier 2|Time 151( 119+31 )ms|Inlined 2Y 0N|IR 229/ 604|CodeSize 2429|Addr 0x7f31475bd810|Src n/a
[engine] opt done Planner>>addConstraintsConsuming:to: <split-6d367020> |AST 22|Tier 2|Time 31( 29+2 )ms|Inlined 0Y 0N|IR 27/ 27|CodeSize 221|Addr 0x7f31475bfc90|Src n/a
[engine] opt done BinaryConstraint>>isSatisfied <split-511d5d04> |AST 17|Tier 2|Time 36( 33+3 )ms|Inlined 0Y 0N|IR 32/ 54|CodeSize 356|Addr 0x7f31475c0410|Src n/a
[engine] opt done Planner>>addConstraintsConsuming:to: <split-682c1e93> |AST 57|Tier 2|Time 149( 126+23 )ms|Inlined 3Y 0N|IR 310/ 446|CodeSize 1731|Addr 0x7f31475c1710|Src n/a
[engine] opt done BinaryConstraint>>isSatisfied <split-27068a50> |AST 17|Tier 2|Time 152( 150+2 )ms|Inlined 0Y 0N|IR 28/ 40|CodeSize 252|Addr 0x7f31475c3c10|Src n/a
[engine] opt done AbstractConstraint>>satisfy:propagate: <split-7b60c3e> |AST 151|Tier 2|Time 1069( 725+344 )ms|Inlined 47Y 0N|IR 3185/ 3488|CodeSize 11601|Addr 0x7f31475c4110|Src n/a
[engine] opt done Planner>>incrementalAdd: <split-599f571f> |AST 51|Tier 2|Time 1253( 931+322 )ms|Inlined 49Y 0N|IR 3247/ 3742|CodeSize 12261|Addr 0x7f31475cf590|Src n/a
[engine] opt done BinaryConstraint>>isSatisfied <split-2b87581> |AST 18|Tier 2|Time 38( 35+4 )ms|Inlined 0Y 0N|IR 93/ 100|CodeSize 417|Addr 0x7f31475ddc10|Src n/a
[engine] opt done BinaryConstraint>>addToGraph |AST 44|Tier 2|Time 475( 202+272 )ms|Inlined 4Y 0N|IR 1470/ 6885|CodeSize 23043|Addr 0x7f31475de710|Src n/a
[engine] opt done BinaryConstraint>>isSatisfied <split-6d467c87> |AST 17|Tier 2|Time 37( 34+3 )ms|Inlined 0Y 0N|IR 32/ 54|CodeSize 356|Addr 0x7f31475ec810|Src n/a
[engine] opt done Planner>>addConstraintsConsuming:to: <split-29182679> |AST 57|Tier 2|Time 145( 114+31 )ms|Inlined 2Y 0N|IR 229/ 604|CodeSize 2429|Addr 0x7f31475ecd90|Src n/a
[engine] opt done Planner>>addConstraintsConsuming:to: <split-57bd802b> |AST 22|Tier 2|Time 32( 30+2 )ms|Inlined 0Y 0N|IR 27/ 27|CodeSize 221|Addr 0x7f31475ef210|Src n/a
[engine] opt done Planner>>addPropagate:mark: <split-6f8f8a80> |AST 143|Tier 2|Time 892( 550+342 )ms|Inlined 28Y 0N|IR 2846/ 4053|CodeSize 18809|Addr 0x7f31475ef690|Src n/a
[engine] opt inv. Vector>>initialize: |AST 30|Calls/Thres 7382/ 3|CallsAndLoop/Thres 7382/ 1000|Src n/a
[engine] opt done Vector>>initialize: |AST 30|Tier 2|Time 132( 121+12 )ms|Inlined 0Y 0N|IR 205/ 442|CodeSize 1376|Addr 0x7f31475fdc90|Src n/a
[engine] opt inv. Vector class>>new: |AST 29|Calls/Thres 8905/ 3|CallsAndLoop/Thres 8905/ 1000|Src n/a
[engine] opt done Vector class>>new: |AST 29|Tier 2|Time 173( 154+20 )ms|Inlined 2Y 0N|IR 290/ 606|CodeSize 1886|Addr 0x7f31475fea90|Src n/a
[engine] opt inv. Behavior>>new <split-3aefae67> |AST 27|Calls/Thres 6447/ 3|CallsAndLoop/Thres 6447/ 1000|Src n/a
[engine] opt done Behavior>>new <split-3aefae67> |AST 27|Tier 2|Time 53( 46+7 )ms|Inlined 0Y 0N|IR 123/ 206|CodeSize 782|Addr 0x7f3147600590|Src n/a
[engine] opt done Planner>>newMark |AST 19|Tier 2|Time 43( 38+5 )ms|Inlined 0Y 0N|IR 76/ 151|CodeSize 496|Addr 0x7f3147601510|Src n/a
[engine] opt done AbstractConstraint>>initialize: |AST 25|Tier 2|Time 172( 160+12 )ms|Inlined 7Y 0N|IR 380/ 688|CodeSize 2155|Addr 0x7f3147602390|Src n/a
[engine] opt done Strength>>stronger: |AST 27|Tier 2|Time 42( 39+3 )ms|Inlined 0Y 0N|IR 39/ 62|CodeSize 312|Addr 0x7f3147603490|Src n/a
[engine] opt done BinaryConstraint>>chooseMethod: |AST 241|Tier 2|Time 172( 138+35 )ms|Inlined 4Y 0N|IR 701/ 1312|CodeSize 4849|Addr 0x7f3147603990|Src n/a
[engine] opt done AbstractConstraint>>satisfy:propagate: <split-1c12f3ee> |AST 151|Tier 2|Time 964( 777+186 )ms|Inlined 39Y 0N|IR 2654/ 2963|CodeSize 10808|Addr 0x7f3147606510|Src n/a
[engine] opt done AbstractConstraint>>satisfy:propagate: |AST 21|Tier 2|Time 51( 47+4 )ms|Inlined 1Y 0N|IR 115/ 123|CodeSize 276|Addr 0x7f3147610d10|Src n/a
[engine] opt done Variable>>determinedBy: |AST 11|Tier 2|Time 33( 29+4 )ms|Inlined 0Y 0N|IR 56/ 89|CodeSize 381|Addr 0x7f3147611610|Src n/a
[engine] opt done BinaryConstraint>>markUnsatisfied |AST 10|Tier 2|Time 32( 27+5 )ms|Inlined 0Y 0N|IR 77/ 273|CodeSize 840|Addr 0x7f3147611d90|Src n/a
[engine] opt done BinaryConstraint>>inputsDo: |AST 60|Tier 2|Time 124( 91+33 )ms|Inlined 5Y 0N|IR 410/ 2140|CodeSize 7189|Addr 0x7f3147612710|Src n/a
[engine] opt done AbstractConstraint>>inputsKnown: |AST 52|Tier 2|Time 59( 56+3 )ms|Inlined 0Y 0N|IR 80/ 97|CodeSize 320|Addr 0x7f3147615290|Src n/a
[engine] opt done UnaryConstraint>>inputsDo: |AST 6|Tier 2|Time 18( 16+1 )ms|Inlined 0Y 0N|IR 19/ 20|CodeSize 181|Addr 0x7f3147615910|Src n/a
[engine] opt done UnaryConstraint>>chooseMethod: |AST 60|Tier 2|Time 87( 77+10 )ms|Inlined 1Y 0N|IR 229/ 327|CodeSize 1195|Addr 0x7f3147615d10|Src n/a
[engine] opt done Variable class>>value: |AST 41|Tier 2|Time 223( 196+27 )ms|Inlined 13Y 0N|IR 655/ 1310|CodeSize 4107|Addr 0x7f3147617690|Src n/a
[engine] opt done UnaryConstraint>>addToGraph |AST 27|Tier 2|Time 288( 148+140 )ms|Inlined 2Y 0N|IR 858/ 3539|CodeSize 11213|Addr 0x7f314761a090|Src n/a
[engine] opt done ScaleConstraint>>inputsDo: |AST 136|Tier 2|Time 348( 253+95 )ms|Inlined 13Y 0N|IR 887/ 5969|CodeSize 19282|Addr 0x7f3147621c90|Src n/a
[engine] opt done ScaleConstraint>>recalculate |AST 181|Tier 2|Time 211( 180+30 )ms|Inlined 9Y 0N|IR 757/ 789|CodeSize 2527|Addr 0x7f3147628e90|Src n/a
[engine] opt done ScaleConstraint>>execute |AST 152|Tier 2|Time 113( 103+11 )ms|Inlined 3Y 0N|IR 388/ 409|CodeSize 1384|Addr 0x7f314762ab90|Src n/a
[engine] opt done Planner>>addConstraintsConsuming:to: <split-4917d36b> |AST 57|Tier 2|Time 361( 210+151 )ms|Inlined 4Y 0N|IR 1118/ 2210|CodeSize 9467|Addr 0x7f314762bc90|Src n/a
[engine] opt done Vector>>at: |AST 39|Tier 2|Time 52( 48+4 )ms|Inlined 0Y 0N|IR 74/ 109|CodeSize 559|Addr 0x7f3147634590|Src n/a
[engine] opt done Integer>>timesRepeat: |AST 46|Tier 2|Time 512( 226+286 )ms|Inlined 9Y 0N|IR 901/ 3172|CodeSize 11886|Addr 0x7f3147635410|Src n/a
[engine] opt done AbstractConstraint>>addConstraint: <split-4463d9d3> |AST 35|Tier 2|Time 3364(1599+1765)ms|Inlined 72Y 4N|IR 7892/13721|CodeSize 60961|Addr 0x7f314763db10|Src n/a
[engine] opt done UnaryConstraint>>initializeVar:strength:addTo: |AST 45|Tier 2|Time 4051(1833+2218)ms|Inlined 79Y 6N|IR 8305/14379|CodeSize 64375|Addr 0x7f314767ae90|Src n/a
[engine] opt done Vector>>remove: |AST 97|Tier 2|Time 376( 294+82 )ms|Inlined 3Y 0N|IR 597/ 1589|CodeSize 6390|Addr 0x7f31476c4e10|Src n/a
[engine] opt done Variable>>removeConstraint: |AST 39|Tier 2|Time 384( 288+96 )ms|Inlined 4Y 0N|IR 649/ 1832|CodeSize 7549|Addr 0x7f31476c9410|Src n/a
[engine] opt done UnaryConstraint>>removeFromGraph |AST 37|Tier 2|Time 424( 289+136 )ms|Inlined 5Y 0N|IR 734/ 1774|CodeSize 7072|Addr 0x7f31476cef10|Src n/a
[engine] opt done Vector>>forEach: <split-27470188> |AST 79|Tier 2|Time 396( 244+151 )ms|Inlined 2Y 0N|IR 890/ 2939|CodeSize 11485|Addr 0x7f31476d4610|Src n/a
[engine] opt done String class>>new: |AST 51|Tier 2|Time 122( 106+15 )ms|Inlined 2Y 1N|IR 213/ 472|CodeSize 1899|Addr 0x7f31476db890|Src n/a
[engine] opt done UnaryConstraint>>markUnsatisfied |AST 10|Tier 2|Time 32( 29+4 )ms|Inlined 0Y 0N|IR 92/ 106|CodeSize 404|Addr 0x7f31476dd010|Src n/a
[engine] opt done SmallInteger>>printString |AST 152|Tier 2|Time 272( 248+24 )ms|Inlined 4Y 1N|IR 361/ 443|CodeSize 1368|Addr 0x7f31476dde90|Src n/a
[engine] opt done Vector>>forEach: <split-ddf20fd> |AST 79|Tier 2|Time 362( 201+161 )ms|Inlined 3Y 0N|IR 1054/ 3847|CodeSize 15984|Addr 0x7f31476dfd90|Src n/a
[engine] opt done Vector class>>new |AST 20|Tier 2|Time 125( 104+22 )ms|Inlined 3Y 0N|IR 317/ 487|CodeSize 1198|Addr 0x7f31476e9010|Src n/a
[engine] opt done Vector>>forEach: <split-4b1abd11> |AST 79|Tier 2|Time 342( 196+146 )ms|Inlined 3Y 0N|IR 941/ 3837|CodeSize 15103|Addr 0x7f31476ed290|Src n/a
[engine] opt done Planner>>extractPlanFromConstraints: |AST 59|Tier 2|Time 1427( 751+676 )ms|Inlined 32Y 0N|IR 3589/ 6877|CodeSize 35731|Addr 0x7f31476f5210|Src n/a
[engine] opt done Strength class>>SymPreferred |AST 10|Tier 2|Time 26( 24+2 )ms|Inlined 0Y 0N|IR 21/ 27|CodeSize 230|Addr 0x7f3147713790|Src n/a
[engine] opt done SequenceableCollection>>copyReplaceFrom:to:with: |AST 177|Tier 2|Time 215( 185+30 )ms|Inlined 3Y 1N|IR 474/ 1035|CodeSize 4845|Addr 0x7f3147714e10|Src n/a
[engine] Truffle runtime statistics for engine 2
Compilations : 187
Success : 177
Temporary Bailouts : 6
org.graalvm.compiler.core.common.RetryableBailoutException: Assumption invalidated while compiling code: Object[Instance<org.graalvm.compiler.truffle.runtime.OptimizedAssumption>]: 6
Permanent Bailouts : 0
Failed : 0
Interrupted : 4
Invalidated : 23
null : 15
frame version : 3
Profiled Argument Types : 2
Queues : 317
Dequeues : 148
Target inlined into only caller : 123
null : 15
Split call node : 7
validRootAssumption Split call node : 2
frame version : 1
Splits : 482
Compilation Accuracy : 0.877005
Queue Accuracy : 0.533123
Compilation Utilization : 1.267826
Remaining Compilation Queue : 0
Time to queue : count= 317, sum= 1677710, min= 2, average= 5292.46, max= 72839 (milliseconds), maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Time waiting in queue : count= 187, sum= 805862, min= 0, average= 4309.43, max= 26477 (milliseconds), maxTarget=Variable>>determinedBy:
Time for compilation : count= 183, sum= 92490, min= 18, average= 505.41, max= 4051 (milliseconds), maxTarget=UnaryConstraint>>initializeVar:strength:addTo:
Truffle Tier : count= 177, sum= 51359, min= 16, average= 290.17, max= 2200 (milliseconds), maxTarget=Planner class>>chainTest:
Graal Tier : count= 177, sum= 22901, min= 1, average= 129.39, max= 1520 (milliseconds), maxTarget=UnaryConstraint>>initializeVar:strength:addTo:
Code Installation : count= 177, sum= 10737, min= 0, average= 60.67, max= 746 (milliseconds), maxTarget=ScaleConstraint class>>var:var:var:var:strength:addTo:
Truffle node count : count= 183, sum= 190142, min= 7, average= 1039.03, max= 6387, maxTarget=UnaryConstraint>>initializeVar:strength:addTo:
Trivial : count= 183, sum= 74815, min= 1, average= 408.83, max= 2512, maxTarget=UnaryConstraint>>initializeVar:strength:addTo:
Non Trivial : count= 183, sum= 115327, min= 6, average= 630.20, max= 3875, maxTarget=UnaryConstraint>>initializeVar:strength:addTo:
Monomorphic : count= 183, sum= 111521, min= 6, average= 609.40, max= 3742, maxTarget=EqualityConstraint class>>var:var:strength:addTo:
Polymorphic : count= 183, sum= 3806, min= 0, average= 20.80, max= 171, maxTarget=AbstractConstraint>>addConstraint:
Megamorphic : count= 183, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Behavior>>new
Truffle call count : count= 183, sum= 2306, min= 0, average= 12.60, max= 87, maxTarget=Planner class>>projectionTest:
Indirect : count= 183, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Behavior>>new
Direct : count= 183, sum= 2306, min= 0, average= 12.60, max= 87, maxTarget=Planner class>>projectionTest:
Dispatched : count= 183, sum= 53, min= 0, average= 0.29, max= 6, maxTarget=Planner class>>projectionTest:
Inlined : count= 183, sum= 2253, min= 0, average= 12.31, max= 81, maxTarget=Planner class>>projectionTest:
---------- :
Cloned : count= 183, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Behavior>>new
Not Cloned : count= 183, sum= 2318, min= 0, average= 12.67, max= 87, maxTarget=Planner class>>projectionTest:
Truffle loops : count= 183, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Behavior>>new
Graal node count :
After Truffle Tier : count= 183, sum= 214765, min= 5, average= 1173.58, max= 8305, maxTarget=UnaryConstraint>>initializeVar:strength:addTo:
After Graal Tier : count= 183, sum= 481275, min= 5, average= 2629.92, max= 21473, maxTarget=Planner>>removePropagateFrom:
Graal compilation result :
Code size : count= 177, sum= 1759500, min= 120, average= 9940.68, max= 84366, maxTarget=Planner>>removePropagateFrom:
Total frame size : count= 177, sum= 37776, min= 32, average= 213.42, max= 1040, maxTarget=ScaleConstraint>>initializeSrc:scale:offset:dst:strength:addTo:
Exception handlers : count= 177, sum= 173, min= 0, average= 0.98, max= 16, maxTarget=Planner class>>projectionTest:
Infopoints : count= 177, sum= 17417, min= 4, average= 98.40, max= 752, maxTarget=Planner>>incrementalAdd:
CALL : count= 177, sum= 13370, min= 4, average= 75.54, max= 579, maxTarget=ScaleConstraint>>initializeSrc:scale:offset:dst:strength:addTo:
IMPLICIT_EXCEPTION : count= 177, sum= 3675, min= 0, average= 20.76, max= 178, maxTarget=Planner>>incrementalAdd:
SAFEPOINT : count= 177, sum= 372, min= 0, average= 2.10, max= 23, maxTarget=Planner>>removePropagateFrom:
Marks : count= 177, sum= 1840, min= 5, average= 10.40, max= 34, maxTarget=Planner class>>chainTest:
Data references : count= 177, sum= 14055, min= 0, average= 79.41, max= 1328, maxTarget=Planner class>>projectionTest:
Raw
5d99b29f-Havlak.trace.log
# Havlak (iterations: 250, problem size: 1500) on Thu May 27 21:35:27 UTC 2021
# `/home/fniephaus/bin/graalvm-ee-java11-21.1.0/bin/trufflesqueak --experimental-options --smalltalk.disable-startup --smalltalk.disable-interrupts --engine.Mode=default --engine.MultiTier=false --engine.TraceCompilation --engine.CompilationStatistics --log.file="/home/fniephaus/dev/are-we-fast-yet/traces/Havlak.trace.log" --quiet --code "FileStream startUp: true. Harness new run: #(nil 'Havlak' 250 1500)" /home/fniephaus/dev/are-we-fast-yet/benchmarks/Smalltalk/AWFY64-sista-fbc.image`
[engine] opt done Behavior>>new <split-41e1455d> |AST 26|Tier 2|Time 154( 136+18 )ms|Inlined 0Y 0N|IR 33/ 97|CodeSize 433|Addr 0x7fd30b918e90|Src n/a
[engine] opt done Vector class>>new: |AST 29|Tier 2|Time 181( 166+16 )ms|Inlined 2Y 0N|IR 57/ 364|CodeSize 1232|Addr 0x7fd30b91e490|Src n/a
[engine] opt done Vector>>at: |AST 39|Tier 2|Time 90( 83+7 )ms|Inlined 0Y 0N|IR 138/ 217|CodeSize 843|Addr 0x7fd30b92b410|Src n/a
[engine] opt done Vector>>append: |AST 163|Tier 2|Time 174( 126+48 )ms|Inlined 0Y 0N|IR 452/ 1711|CodeSize 7565|Addr 0x7fd30b94a390|Src n/a
[engine] opt done Vector>>forEach: <split-61e45f87> |AST 79|Tier 2|Time 1272( 642+630 )ms|Inlined 22Y 0N|IR 2475/ 8346|CodeSize 35865|Addr 0x7fd30b973790|Src n/a
[engine] opt done Vector>>forEach: <split-4d8539de> |AST 79|Tier 2|Time 311( 227+84 )ms|Inlined 10Y 0N|IR 616/ 3045|CodeSize 11695|Addr 0x7fd30b99a310|Src n/a
[engine] opt done Integer>>>> |AST 31|Tier 2|Time 36( 33+3 )ms|Inlined 0Y 0N|IR 39/ 111|CodeSize 462|Addr 0x7fd30b99fb90|Src n/a
[engine] opt done HavlakLoopFinder>>identifyEdges: |AST 128|Tier 2|Time 1484( 601+883 )ms|Inlined 22Y 0N|IR 2415/ 6632|CodeSize 33310|Addr 0x7fd30b9a0110|Src n/a
[engine] opt done Object>>~= <split-45394b31> |AST 26|Tier 2|Time 49( 46+2 )ms|Inlined 1Y 0N|IR 27/ 34|CodeSize 250|Addr 0x7fd30b9bea10|Src n/a
[engine] opt done Vector>>hasSome: <split-6ecd665> |AST 81|Tier 2|Time 113( 85+28 )ms|Inlined 1Y 0N|IR 239/ 1284|CodeSize 4744|Addr 0x7fd30b9c0810|Src n/a
[engine] opt done SomDictionary>>bucket: |AST 33|Tier 2|Time 75( 70+5 )ms|Inlined 1Y 0N|IR 155/ 115|CodeSize 599|Addr 0x7fd30b9c2e10|Src n/a
[engine] opt done Vector>>forEach: <split-3b0ca5e1> |AST 37|Tier 2|Time 40( 38+2 )ms|Inlined 0Y 0N|IR 36/ 56|CodeSize 288|Addr 0x7fd30b9c3590|Src n/a
[engine] opt done SomSet>>hasSome: <split-585ac855> |AST 23|Tier 2|Time 211( 91+120 )ms|Inlined 2Y 0N|IR 290/ 1347|CodeSize 4821|Addr 0x7fd30b9c8a10|Src n/a
[engine] opt done UnionFindNode>>findSet |AST 139|Tier 2|Time 286( 276+10 )ms|Inlined 9Y 0N|IR 363/ 238|CodeSize 755|Addr 0x7fd30b9cf990|Src n/a
[engine] opt done Vector>>size |AST 18|Tier 2|Time 33( 30+3 )ms|Inlined 0Y 0N|IR 32/ 110|CodeSize 451|Addr 0x7fd30b9d0690|Src n/a
[engine] opt done SomDictionary>>hash: |AST 60|Tier 2|Time 69( 66+3 )ms|Inlined 1Y 0N|IR 33/ 106|CodeSize 436|Addr 0x7fd30b9d0c10|Src n/a
[engine] opt done SomDictionary>>bucketIdx: |AST 40|Tier 2|Time 58( 52+6 )ms|Inlined 0Y 0N|IR 91/ 211|CodeSize 770|Addr 0x7fd30b9d1f10|Src n/a
[engine] opt done Vector class>>new |AST 20|Tier 2|Time 90( 85+5 )ms|Inlined 3Y 0N|IR 49/ 290|CodeSize 1040|Addr 0x7fd30b9d4a90|Src n/a
[engine] opt done HavlakLoopFinder>>Unvisited |AST 8|Tier 2|Time 22( 20+2 )ms|Inlined 0Y 0N|IR 18/ 52|CodeSize 277|Addr 0x7fd30b9d5990|Src n/a
[engine] opt deopt Vector>>at: |AST 39|Src n/a
[engine] opt done Integer>>timesRepeat: |AST 46|Tier 2|Time 100( 67+33 )ms|Inlined 0Y 0N|IR 162/ 1819|CodeSize 5843|Addr 0x7fd30b9dd790|Src n/a
[engine] opt inv. Vector>>at: |AST 41|Calls/Thres 17145/ 3|CallsAndLoop/Thres 17152/ 1000|Src n/a
[engine] opt done Vector>>at: |AST 41|Tier 2|Time 95( 83+12 )ms|Inlined 0Y 0N|IR 149/ 275|CodeSize 1032|Addr 0x7fd30b9e5090|Src n/a
[engine] opt inv. Vector>>forEach: <split-4d8539de> |AST 79|Calls/Thres 856/ 3|CallsAndLoop/Thres 10272/ 1000|Src n/a|Reason Latest layout assumption Layout no longer valid
[engine] opt inv. HavlakLoopFinder>>identifyEdges: |AST 128|Calls/Thres 903/ 3|CallsAndLoop/Thres 10836/ 1000|Src n/a|Reason Latest layout assumption Layout no longer valid
[engine] opt done Vector>>at:put: |AST 201|Tier 2|Time 177( 122+55 )ms|Inlined 0Y 0N|IR 483/ 1891|CodeSize 8279|Addr 0x7fd30b9ea290|Src n/a
[engine] opt done DictIdEntry class>>new:key:value:next: |AST 40|Tier 2|Time 77( 73+3 )ms|Inlined 2Y 0N|IR 50/ 110|CodeSize 449|Addr 0x7fd30b9fa590|Src n/a
[engine] opt deopt Vector>>forEach: <split-4d8539de> |AST 79|Src n/a
[engine] opt done Behavior>>new <split-bcb09a6> |AST 26|Tier 2|Time 45( 42+3 )ms|Inlined 0Y 0N|IR 33/ 97|CodeSize 433|Addr 0x7fd30b9fd610|Src n/a
[engine] opt done DictEntry>>init:key:value:next: |AST 26|Tier 2|Time 36( 32+4 )ms|Inlined 0Y 0N|IR 136/ 281|CodeSize 756|Addr 0x7fd30ba02890|Src n/a
[engine] opt done Vector>>forEach: <split-5f78de22> |AST 79|Tier 2|Time 965( 389+576 )ms|Inlined 17Y 0N|IR 2103/ 6802|CodeSize 29091|Addr 0x7fd30ba03110|Src n/a
[engine] opt deopt SomSet>>hasSome: <split-585ac855> |AST 23|Src n/a
[engine] opt done SomDictionary>>at:put: <split-5173200b> |AST 179|Tier 2|Time 188( 186+2 )ms|Inlined 3Y 0N|IR 5/ 5|CodeSize 120|Addr 0x7fd30ba19e90|Src n/a
[engine] opt deopt Vector>>forEach: <split-5f78de22> |AST 79|Src n/a
[engine] opt done SomDictionary>>transferEntries: |AST 194|Tier 2|Time 348( 281+66 )ms|Inlined 3Y 0N|IR 814/ 1706|CodeSize 7718|Addr 0x7fd30ba23090|Src n/a
[engine] opt done Vector>>hasSome: <split-6fe46b62> |AST 79|Tier 2|Time 159( 82+76 )ms|Inlined 1Y 0N|IR 215/ 4160|CodeSize 14039|Addr 0x7fd30ba2b510|Src n/a
[engine] opt deopt Vector>>forEach: <split-61e45f87> |AST 79|Src n/a
[engine] opt deopt Vector>>hasSome: <split-6fe46b62> |AST 79|Src n/a
[engine] opt deopt Vector>>hasSome: <split-6ecd665> |AST 81|Src n/a
[engine] opt deopt UnionFindNode>>findSet |AST 139|Src n/a
[engine] opt done Vector>>forEach: <split-4b6ac111> |AST 79|Tier 2|Time 946( 415+531 )ms|Inlined 18Y 0N|IR 2168/ 6724|CodeSize 29305|Addr 0x7fd30ba34090|Src n/a
[engine] opt inv. Vector>>hasSome: <split-6fe46b62> |AST 81|Calls/Thres 26401/ 3|CallsAndLoop/Thres 62433/ 1000|Src n/a
[engine] opt done Vector>>hasSome: <split-6fe46b62> |AST 81|Tier 2|Time 165( 82+83 )ms|Inlined 1Y 0N|IR 245/ 4397|CodeSize 15123|Addr 0x7fd30ba52090|Src n/a
[engine] opt done SomSet>>hasSome: <split-516ebdf8> |AST 23|Tier 2|Time 189( 89+100 )ms|Inlined 2Y 0N|IR 296/ 4482|CodeSize 15074|Addr 0x7fd30ba58b90|Src n/a
[engine] opt inv. Vector>>hasSome: <split-6ecd665> |AST 81|Calls/Thres 18614/ 3|CallsAndLoop/Thres 22325/ 1000|Src n/a
[engine] opt done Vector>>hasSome: <split-6ecd665> |AST 81|Tier 2|Time 108( 79+30 )ms|Inlined 1Y 0N|IR 250/ 1284|CodeSize 4781|Addr 0x7fd30ba5ff90|Src n/a
[engine] opt inv. Vector>>forEach: <split-5f78de22> |AST 79|Calls/Thres 7699/ 3|CallsAndLoop/Thres 31620/ 1000|Src n/a
[engine] opt done Vector>>forEach: <split-5f78de22> |AST 79|Tier 2|Time 1061( 524+537 )ms|Inlined 17Y 0N|IR 2173/ 6754|CodeSize 29491|Addr 0x7fd30ba62510|Src n/a
[engine] opt done HavlakLoopFinder>>findLoops |AST 760|Tier 2|Time 5185(1890+3295)ms|Inlined 61Y 11N|IR 11412/41700|CodeSize 178109|Addr 0x7fd30ba78610|Src n/a
[engine] opt done Behavior>>new <split-17ca8b92> |AST 27|Tier 2|Time 50( 44+6 )ms|Inlined 0Y 0N|IR 123/ 206|CodeSize 782|Addr 0x7fd30bac9610|Src n/a
[engine] opt done SomSet>>initialize: |AST 25|Tier 2|Time 97( 86+11 )ms|Inlined 3Y 0N|IR 123/ 870|CodeSize 2779|Addr 0x7fd30baca310|Src n/a
[engine] opt done HavlakLoopFinder>>setLoopAttribute:nodePool:loop: |AST 137|Tier 2|Time 775( 447+329 )ms|Inlined 16Y 0N|IR 1946/ 4453|CodeSize 18427|Addr 0x7fd30bacc690|Src n/a
[engine] opt done UnionFindNode class>>new |AST 26|Tier 2|Time 75( 72+3 )ms|Inlined 3Y 0N|IR 33/ 98|CodeSize 433|Addr 0x7fd30bade410|Src n/a
[engine] opt done Behavior>>new <split-3eba57a7> |AST 28|Tier 2|Time 66( 63+3 )ms|Inlined 1Y 0N|IR 33/ 98|CodeSize 433|Addr 0x7fd30badea90|Src n/a
[engine] opt done Vector>>forEach: <split-74fef3f7> |AST 79|Tier 2|Time 814( 387+427 )ms|Inlined 15Y 0N|IR 1642/ 4956|CodeSize 23090|Addr 0x7fd30badf110|Src n/a
[engine] opt done HavlakLoopFinder>>stepD:nodePool: |AST 45|Tier 2|Time 908( 546+363 )ms|Inlined 17Y 0N|IR 1816/ 4334|CodeSize 21225|Addr 0x7fd30baef390|Src n/a
[engine] opt done Vector>>removeFirst |AST 53|Tier 2|Time 81( 76+5 )ms|Inlined 1Y 0N|IR 124/ 164|CodeSize 656|Addr 0x7fd30bb02e10|Src n/a
[engine] opt done SomSet>>size |AST 20|Tier 2|Time 51( 47+3 )ms|Inlined 1Y 0N|IR 46/ 128|CodeSize 536|Addr 0x7fd30bb04690|Src n/a
[engine] opt done HavlakLoopFinder>>MaxNonBackPreds |AST 14|Tier 2|Time 25( 24+2 )ms|Inlined 0Y 0N|IR 18/ 52|CodeSize 277|Addr 0x7fd30bb05410|Src n/a
[engine] opt inv. Vector>>forEach: <split-61e45f87> |AST 79|Calls/Thres 37372/ 3|CallsAndLoop/Thres 82769/ 1000|Src n/a
[engine] opt done Vector>>forEach: <split-61e45f87> |AST 79|Tier 2|Time 1654( 660+994 )ms|Inlined 26Y 0N|IR 3590/11739|CodeSize 56808|Addr 0x7fd30bb06210|Src n/a
[engine] opt done HavlakLoopFinder>>stepEProcessNonBackPreds:nodePool:workList:x:|AST 58|Tier 2|Time 2408( 878+1530)ms|Inlined 29Y 0N|IR 4000/13391|CodeSize 64564|Addr 0x7fd30bb2c290|Src n/a
[engine] opt done UnionFindNode>>union: |AST 11|Tier 2|Time 28( 25+3 )ms|Inlined 0Y 0N|IR 60/ 164|CodeSize 445|Addr 0x7fd30bb5a290|Src n/a
[engine] opt inv. UnionFindNode>>findSet |AST 156|Calls/Thres 54079/ 3|CallsAndLoop/Thres 65112/ 1000|Src n/a
[engine] opt done UnionFindNode>>findSet |AST 156|Tier 2|Time 370( 277+92 )ms|Inlined 12Y 0N|IR 954/ 2136|CodeSize 9207|Addr 0x7fd30bb5cf10|Src n/a
[engine] opt inv. SomSet>>hasSome: <split-585ac855> |AST 23|Calls/Thres 24841/ 3|CallsAndLoop/Thres 24841/ 1000|Src n/a
[engine] opt done SomSet>>hasSome: <split-585ac855> |AST 23|Tier 2|Time 124( 87+37 )ms|Inlined 2Y 0N|IR 301/ 1347|CodeSize 4763|Addr 0x7fd30bb63a90|Src n/a
[engine] opt done SomSet>>forEach: |AST 24|Tier 2|Time 1948( 812+1136)ms|Inlined 27Y 0N|IR 3635/11812|CodeSize 57731|Addr 0x7fd30bb66590|Src n/a
[engine] opt done SomSet>>add: <split-5bb8f9e2> |AST 40|Tier 2|Time 285( 197+88 )ms|Inlined 5Y 0N|IR 804/ 2093|CodeSize 8631|Addr 0x7fd30bb91590|Src n/a
[engine] opt inv. Vector>>forEach: <split-3b0ca5e1> |AST 79|Calls/Thres 53362/ 3|CallsAndLoop/Thres 53373/ 1000|Src n/a
[engine] opt done Vector>>forEach: <split-3b0ca5e1> |AST 79|Tier 2|Time 126( 95+31 )ms|Inlined 2Y 0N|IR 266/ 1382|CodeSize 5065|Addr 0x7fd30bb97f10|Src n/a
[engine] opt done SimpleLoop>>addNode: |AST 24|Tier 2|Time 450( 331+119 )ms|Inlined 6Y 0N|IR 856/ 1987|CodeSize 8841|Addr 0x7fd30bb9a890|Src n/a
[engine] opt done SomSet>>add: <split-4d847d32> |AST 40|Tier 2|Time 281( 189+92 )ms|Inlined 5Y 0N|IR 801/ 1938|CodeSize 8213|Addr 0x7fd30bba1810|Src n/a
[engine] opt done HavlakLoopFinder>>findLoops <split-65327f5> |AST 760|Tier 2|Time 5134(2242+2892)ms|Inlined 63Y 7N|IR 10458/37939|CodeSize 167244|Addr 0x7fd30bba7a10|Src n/a
[engine] opt done Vector>>hasSome: <split-5bb3131b> |AST 81|Tier 2|Time 124( 84+40 )ms|Inlined 1Y 0N|IR 245/ 2212|CodeSize 7302|Addr 0x7fd30bbfe890|Src n/a
[engine] opt done Vector>>forEach: <split-6569dded> |AST 79|Tier 2|Time 281( 156+125 )ms|Inlined 2Y 0N|IR 686/ 2829|CodeSize 11102|Addr 0x7fd30bc01910|Src n/a
[engine] opt done Symbol>>= <split-466d49f0> |AST 26|Tier 2|Time 38( 36+2 )ms|Inlined 0Y 0N|IR 27/ 37|CodeSize 240|Addr 0x7fd30bc08590|Src n/a
[engine] opt done Object>>~= <split-710d7aff> |AST 26|Tier 2|Time 52( 49+3 )ms|Inlined 1Y 0N|IR 95/ 53|CodeSize 341|Addr 0x7fd30bc08d10|Src n/a
[engine] opt done HavlakLoopFinder>>identifyEdges: |AST 128|Tier 2|Time 1446( 637+809 )ms|Inlined 22Y 0N|IR 2505/ 6926|CodeSize 32118|Addr 0x7fd30bc09610|Src n/a
[engine] opt done Symbol>>= <split-2d7e1102> |AST 28|Tier 2|Time 99( 96+3 )ms|Inlined 0Y 0N|IR 58/ 44|CodeSize 324|Addr 0x7fd30bc24610|Src n/a
[engine] opt done BasicBlock>>numPred |AST 20|Tier 2|Time 52( 48+4 )ms|Inlined 1Y 0N|IR 46/ 128|CodeSize 536|Addr 0x7fd30bc24f10|Src n/a
[engine] opt done Vector>>forEach: <split-2adddc06> |AST 79|Tier 2|Time 988( 493+495 )ms|Inlined 23Y 0N|IR 1921/ 7065|CodeSize 33820|Addr 0x7fd30bc25b90|Src n/a
[engine] opt done HavlakLoopFinder>>findLoops |AST 23|Tier 2|Time 236( 145+91 )ms|Inlined 1Y 0N|IR 527/ 1769|CodeSize 7909|Addr 0x7fd30bc3a690|Src n/a
[engine] opt done DictEntry>>value: |AST 11|Tier 2|Time 30( 27+3 )ms|Inlined 0Y 0N|IR 73/ 88|CodeSize 273|Addr 0x7fd30bc3f810|Src n/a
[engine] opt done HavlakLoopFinder>>stepD:nodePool: |AST 55|Tier 2|Time 612( 396+217 )ms|Inlined 14Y 0N|IR 1455/ 3876|CodeSize 18528|Addr 0x7fd30bc3fe90|Src n/a
[engine] opt done HavlakLoopFinder>>processEdges:w: |AST 57|Tier 2|Time 1042( 489+553 )ms|Inlined 21Y 0N|IR 2233/ 5285|CodeSize 23910|Addr 0x7fd30bc4cc90|Src n/a
[engine] opt done UnionFindNode>>loop: |AST 11|Tier 2|Time 97( 94+3 )ms|Inlined 0Y 0N|IR 60/ 165|CodeSize 445|Addr 0x7fd30bc65f90|Src n/a
[engine] opt done LoopStructureGraph>>createNewLoop:reducible: |AST 80|Tier 2|Time 832( 532+301 )ms|Inlined 23Y 0N|IR 1891/ 5149|CodeSize 21974|Addr 0x7fd30bc6f190|Src n/a
[engine] opt deopt LoopStructureGraph>>createNewLoop:reducible: |AST 80|Src n/a
[engine] opt done Behavior>>new <split-6ad11a56> |AST 26|Tier 2|Time 48( 42+6 )ms|Inlined 0Y 0N|IR 94/ 374|CodeSize 1320|Addr 0x7fd30bc7e690|Src n/a
[engine] opt deopt SimpleLoop class>>basicBlock:reducible: <split-726a6b94> |AST 34|Src n/a
[engine] opt done SimpleLoop class>>basicBlock:reducible: <split-726a6b94> |AST 34|Tier 2|Time 518( 344+174 )ms|Inlined 20Y 0N|IR 1310/ 3370|CodeSize 13395|Addr 0x7fd30bc7f090|Src n/a
[engine] opt done HavlakLoopFinder>>setLoopAttribute:nodePool:loop: |AST 60|Tier 2|Time 1150( 509+641 )ms|Inlined 19Y 0N|IR 2285/ 5910|CodeSize 25926|Addr 0x7fd30bc88910|Src n/a
[engine] opt done SomSet>>add: <split-3ff57625> |AST 40|Tier 2|Time 284( 198+86 )ms|Inlined 5Y 0N|IR 793/ 1884|CodeSize 8268|Addr 0x7fd30bca1e90|Src n/a
[engine] opt inv. LoopStructureGraph>>createNewLoop:reducible: |AST 80|Calls/Thres 52529/ 3|CallsAndLoop/Thres 52529/ 1000|Src n/a
[engine] opt done LoopStructureGraph>>createNewLoop:reducible: |AST 80|Tier 2|Time 797( 422+375 )ms|Inlined 23Y 0N|IR 1891/ 5295|CodeSize 23687|Addr 0x7fd30bcb0590|Src n/a
[engine] opt inv. SimpleLoop class>>basicBlock:reducible: <split-726a6b94> |AST 34|Calls/Thres 52527/ 3|CallsAndLoop/Thres 52527/ 1000|Src n/a
[engine] opt done SimpleLoop class>>basicBlock:reducible: <split-726a6b94> |AST 34|Tier 2|Time 597( 410+187 )ms|Inlined 20Y 0N|IR 1310/ 3522|CodeSize 14179|Addr 0x7fd30bcc1810|Src n/a
[engine] opt done SimpleLoop>>init:reducible: <split-522b2631> |AST 93|Tier 2|Time 522( 387+135 )ms|Inlined 18Y 0N|IR 1231/ 3021|CodeSize 12873|Addr 0x7fd30bccb910|Src n/a
[engine] opt inv. SomSet>>add: <split-3ff57625> |AST 40|Calls/Thres 52528/ 3|CallsAndLoop/Thres 52528/ 1000|Src n/a
[engine] opt done SomSet>>add: <split-3ff57625> |AST 40|Tier 2|Time 290( 197+93 )ms|Inlined 5Y 0N|IR 793/ 2036|CodeSize 8803|Addr 0x7fd30bcd3c10|Src n/a
[engine] opt done SimpleLoop>>parent: |AST 28|Tier 2|Time 350( 212+139 )ms|Inlined 7Y 0N|IR 913/ 2061|CodeSize 8428|Addr 0x7fd30bcda010|Src n/a
[engine] opt done SimpleLoop>>addChildLoop: |AST 24|Tier 2|Time 311( 200+110 )ms|Inlined 6Y 0N|IR 848/ 1933|CodeSize 8101|Addr 0x7fd30bce1710|Src n/a
[engine] opt done SomDictionary>>removeAll |AST 33|Tier 2|Time 182( 176+6 )ms|Inlined 0Y 0N|IR 129/ 305|CodeSize 939|Addr 0x7fd30bce8010|Src n/a
[engine] opt done Object>>~= <split-34004818> |AST 26|Tier 2|Time 46( 43+2 )ms|Inlined 1Y 0N|IR 27/ 34|CodeSize 250|Addr 0x7fd30bce8b10|Src n/a
[engine] opt done DictIdEntry>>match:key: |AST 30|Tier 2|Time 40( 36+4 )ms|Inlined 0Y 0N|IR 75/ 77|CodeSize 468|Addr 0x7fd30bcef990|Src n/a
[engine] opt done SomSet>>add: <split-77128dab> |AST 40|Tier 2|Time 401( 309+92 )ms|Inlined 5Y 0N|IR 793/ 2036|CodeSize 8803|Addr 0x7fd30bce9590|Src n/a
[engine] opt done Vector>>isEmpty |AST 18|Tier 2|Time 36( 33+2 )ms|Inlined 0Y 0N|IR 31/ 46|CodeSize 276|Addr 0x7fd30bceff90|Src n/a
[engine] opt done HavlakLoopFinder>>isAncestor:v: |AST 41|Tier 2|Time 54( 50+4 )ms|Inlined 0Y 0N|IR 103/ 108|CodeSize 545|Addr 0x7fd30bcf0410|Src n/a
[engine] opt done SomDictionary>>at: |AST 86|Tier 2|Time 147( 140+7 )ms|Inlined 5Y 0N|IR 287/ 243|CodeSize 1027|Addr 0x7fd30bcf0a90|Src n/a
[engine] opt done UnionFindNode>>initialize |AST 10|Tier 2|Time 29( 26+2 )ms|Inlined 0Y 0N|IR 68/ 77|CodeSize 255|Addr 0x7fd30bcf1710|Src n/a
[engine] opt done Object>>= |AST 14|Tier 2|Time 29( 25+4 )ms|Inlined 0Y 0N|IR 76/ 131|CodeSize 513|Addr 0x7fd30bcf1d90|Src n/a
[engine] opt done SomSet class>>new |AST 28|Tier 2|Time 124( 107+17 )ms|Inlined 5Y 0N|IR 261/ 632|CodeSize 1834|Addr 0x7fd30bcf2c90|Src n/a
[engine] opt done HavlakLoopFinder>>stepEProcessNonBackPreds:nodePool:workList:x:|AST 213|Tier 2|Time 1248( 732+516 )ms|Inlined 25Y 0N|IR 3323/10925|CodeSize 53330|Addr 0x7fd30bcf4110|Src n/a
[engine] opt done SomSet>>contains: |AST 25|Tier 2|Time 135( 112+23 )ms|Inlined 3Y 0N|IR 318/ 452|CodeSize 1435|Addr 0x7fd30bd14f10|Src n/a
[engine] opt done SomIdentitySet>>contains: |AST 14|Tier 2|Time 28( 26+2 )ms|Inlined 0Y 0N|IR 25/ 25|CodeSize 205|Addr 0x7fd30bd16f90|Src n/a
[engine] opt done SomIdentitySet>>contains: |AST 25|Tier 2|Time 218( 109+109 )ms|Inlined 3Y 0N|IR 315/ 456|CodeSize 1656|Addr 0x7fd30bd17390|Src n/a
[engine] opt deopt SomIdentitySet>>contains: |AST 25|Src n/a
[engine] opt done HavlakLoopFinder>>initAllNodes |AST 34|Tier 2|Time 120( 118+2 )ms|Inlined 5Y 0N|IR 5/ 5|CodeSize 120|Addr 0x7fd30bd19590|Src n/a
[engine] opt done HavlakLoopFinder>>processEdges:w: |AST 125|Tier 2|Time 721( 395+326 )ms|Inlined 17Y 0N|IR 1991/ 4682|CodeSize 21259|Addr 0x7fd30bd19a10|Src n/a
[engine] opt inv. SomIdentitySet>>contains: |AST 25|Calls/Thres 130850/ 3|CallsAndLoop/Thres 130850/ 1000|Src n/a
[engine] opt done SomIdentitySet>>contains: |AST 25|Tier 2|Time 138( 108+29 )ms|Inlined 3Y 0N|IR 315/ 442|CodeSize 1718|Addr 0x7fd30bd29410|Src n/a
[engine] opt done UnionFindNode>>initNode:dfs: |AST 20|Tier 2|Time 36( 31+5 )ms|Inlined 0Y 0N|IR 105/ 202|CodeSize 719|Addr 0x7fd30bd2b610|Src n/a
[engine] opt done SomIdentityDictionary>>newEntry:value:hash: |AST 31|Tier 2|Time 91( 87+3 )ms|Inlined 3Y 0N|IR 51/ 110|CodeSize 462|Addr 0x7fd30bd2c010|Src n/a
[engine] opt done SomDictionary>>insertBucketEntry:value:hash:head: |AST 122|Tier 2|Time 154( 143+11 )ms|Inlined 7Y 0N|IR 317/ 480|CodeSize 1272|Addr 0x7fd30b775910|Src n/a
[engine] opt deopt Vector>>forEach: <split-61e45f87> |AST 79|Src n/a
[engine] opt inv. HavlakLoopFinder>>findLoops <split-65327f5> |AST 760|Calls/Thres 14/ 3|CallsAndLoop/Thres 218974/ 1000|Src n/a|Reason Profiled Argument Types
[engine] opt inv. HavlakLoopFinder>>findLoops |AST 760|Calls/Thres 1501/ 3|CallsAndLoop/Thres 63641/ 1000|Src n/a|Reason Profiled Argument Types
[engine] opt deopt HavlakLoopFinder>>setLoopAttribute:nodePool:loop: |AST 60|Src n/a
[engine] opt done SomDictionary>>at:put: <split-1813f3e9> |AST 115|Tier 2|Time 251( 230+21 )ms|Inlined 11Y 0N|IR 508/ 743|CodeSize 2380|Addr 0x7fd30b76b090|Src n/a
[engine] opt done HavlakLoopFinder>>doDFS:current: |AST 226|Tier 2|Time 2088(1084+1004)ms|Inlined 68Y 1N|IR 3671/ 9249|CodeSize 48381|Addr 0x7fd30bd2cc10|Src n/a
[engine] opt inv. HavlakLoopFinder>>setLoopAttribute:nodePool:loop: |AST 60|Calls/Thres 53985/ 3|CallsAndLoop/Thres 53985/ 1000|Src n/a
[engine] opt done HavlakLoopFinder>>setLoopAttribute:nodePool:loop: |AST 60|Tier 2|Time 1229( 576+654 )ms|Inlined 19Y 0N|IR 2285/ 6068|CodeSize 27822|Addr 0x7fd30bd56510|Src n/a
[engine] opt inv. Vector>>forEach: <split-61e45f87> |AST 80|Calls/Thres 37375/ 3|CallsAndLoop/Thres 84275/ 1000|Src n/a
[engine] opt done Vector>>forEach: <split-61e45f87> |AST 80|Tier 2|Time 2688(1010+1678)ms|Inlined 46Y 1N|IR 4842/18949|CodeSize 83147|Addr 0x7fd30bd71710|Src n/a
[engine] opt inv. SimpleLoop>>parent: |AST 28|Calls/Thres 7700/ 3|CallsAndLoop/Thres 7700/ 1000|Src n/a
[engine] opt done SimpleLoop>>parent: |AST 28|Tier 2|Time 358( 205+153 )ms|Inlined 7Y 0N|IR 913/ 2213|CodeSize 8979|Addr 0x7fd30b82f110|Src n/a
[engine] opt inv. SomSet>>forEach: |AST 24|Calls/Thres 65643/ 3|CallsAndLoop/Thres 65643/ 1000|Src n/a
[engine] opt done SomSet>>forEach: |AST 24|Tier 2|Time 2979(1016+1963)ms|Inlined 47Y 1N|IR 4906/19278|CodeSize 81609|Addr 0x7fd30bdaeb90|Src n/a
[engine] opt done LoopTesterApp>>addDummyLoops: |AST 21|Tier 2|Time 230( 207+22 )ms|Inlined 16Y 1N|IR 382/ 1411|CodeSize 5007|Addr 0x7fd30b82c990|Src n/a
[engine] opt inv. SimpleLoop>>addChildLoop: |AST 24|Calls/Thres 7701/ 3|CallsAndLoop/Thres 7701/ 1000|Src n/a
[engine] opt done SimpleLoop>>addChildLoop: |AST 24|Tier 2|Time 326( 206+120 )ms|Inlined 6Y 0N|IR 848/ 2085|CodeSize 8802|Addr 0x7fd30bdf2010|Src n/a
[engine] opt done Behavior>>new <split-6f012914> |AST 26|Tier 2|Time 50( 45+6 )ms|Inlined 0Y 0N|IR 93/ 288|CodeSize 1058|Addr 0x7fd30b82c090|Src n/a
[engine] opt done HavlakLoopFinder>>init:lsg: |AST 68|Tier 2|Time 199( 179+20 )ms|Inlined 12Y 0N|IR 238/ 1296|CodeSize 3743|Addr 0x7fd30b82a110|Src n/a
[engine] opt done SomIdentityDictionary class>>new |AST 18|Tier 2|Time 238( 233+5 )ms|Inlined 3Y 0N|IR 45/ 289|CodeSize 1042|Addr 0x7fd30b829790|Src n/a
[engine] opt done SomDictionary class>>new: |AST 29|Tier 2|Time 85( 80+5 )ms|Inlined 2Y 0N|IR 59/ 318|CodeSize 1097|Addr 0x7fd30b828e10|Src n/a
[engine] opt done Behavior>>new <split-61533ae> |AST 26|Tier 2|Time 44( 41+3 )ms|Inlined 0Y 0N|IR 33/ 97|CodeSize 433|Addr 0x7fd30b828810|Src n/a
[engine] opt done SomDictionary>>initialize: |AST 26|Tier 2|Time 55( 50+5 )ms|Inlined 0Y 0N|IR 116/ 268|CodeSize 761|Addr 0x7fd30bdf8f10|Src n/a
[engine] opt done Vector>>forEach: <split-4ebadd3d> |AST 79|Tier 2|Time 313( 227+85 )ms|Inlined 10Y 0N|IR 616/ 3066|CodeSize 12130|Addr 0x7fd30bdf9890|Src n/a
[engine] opt done LoopTesterApp>>buildStraight:n: <split-38499e48> |AST 95|Tier 2|Time 2020( 712+1308)ms|Inlined 30Y 0N|IR 3070/ 9356|CodeSize 44822|Addr 0x7fd30be00e90|Src n/a
[engine] opt done HavlakLoopFinder>>findLoops <split-65327f5> |AST 760|Tier 2|Time 4736(2162+2575)ms|Inlined 59Y 7N|IR 9876/35991|CodeSize 156892|Addr 0x7fd30be2d510|Src n/a
[engine] opt done SimpleLoop>>depthLevel: |AST 11|Tier 2|Time 29( 26+3 )ms|Inlined 0Y 0N|IR 74/ 88|CodeSize 273|Addr 0x7fd30be7b810|Src n/a
[engine] opt done HavlakLoopFinder>>findLoops <split-72ba28ee> |AST 760|Tier 2|Time 3625(1799+1826)ms|Inlined 47Y 7N|IR 8476/32313|CodeSize 138852|Addr 0x7fd30be7be90|Src n/a
[engine] opt done Vector>>forEach: <split-6d367020> |AST 79|Tier 2|Time 676( 352+323 )ms|Inlined 20Y 1N|IR 1376/ 2801|CodeSize 10290|Addr 0x7fd30beba390|Src n/a
[engine] opt done SomSet>>forEach: <split-3e134896> |AST 24|Tier 2|Time 872( 392+480 )ms|Inlined 21Y 1N|IR 1414/ 2841|CodeSize 10277|Addr 0x7fd30bec7b10|Src n/a
[engine] opt done Integer>>timesRepeat: <split-4a03bb68> |AST 46|Tier 2|Time 944( 878+66 )ms|Inlined 1Y 1N|IR 242/ 2796|CodeSize 10209|Addr 0x7fd30bed5c90|Src n/a
[engine] opt done Behavior>>new <split-6f6962ba> |AST 26|Tier 2|Time 47( 44+3 )ms|Inlined 0Y 0N|IR 33/ 97|CodeSize 433|Addr 0x7fd30bed9e90|Src n/a
[engine] opt done BasicBlock>>init: |AST 47|Tier 2|Time 127( 115+11 )ms|Inlined 6Y 0N|IR 151/ 762|CodeSize 2330|Addr 0x7fd30bedaa90|Src n/a
[engine] opt done LoopTesterApp>>buildStraight:n: <split-4905c46b> |AST 95|Tier 2|Time 1761( 573+1188)ms|Inlined 30Y 0N|IR 3070/ 9356|CodeSize 44822|Addr 0x7fd30bedc310|Src n/a
[engine] opt done Vector>>forEach: <split-4e868ef5> |AST 79|Tier 2|Time 664( 382+282 )ms|Inlined 9Y 0N|IR 1206/ 5175|CodeSize 21443|Addr 0x7fd30bf0a990|Src n/a
[engine] opt done LoopTesterApp>>buildStraight:n: <split-17ae7628> |AST 95|Tier 2|Time 1759( 601+1158)ms|Inlined 29Y 0N|IR 2843/ 9090|CodeSize 43589|Addr 0x7fd30bf18690|Src n/a
[engine] opt done Integer>>timesRepeat: <split-71c905a3> |AST 46|Tier 2|Time 308( 243+65 )ms|Inlined 17Y 1N|IR 505/ 2683|CodeSize 10976|Addr 0x7fd30bf42210|Src n/a
[engine] opt done Vector>>forEach: <split-67a056f1> |AST 79|Tier 2|Time 1046( 482+564 )ms|Inlined 23Y 0N|IR 1921/ 7065|CodeSize 35007|Addr 0x7fd30bf46b10|Src n/a
[engine] opt done HavlakLoopFinder>>stepEProcessNonBackPreds:nodePool:workList:x:|AST 14|Tier 2|Time 29( 27+2 )ms|Inlined 0Y 0N|IR 25/ 25|CodeSize 205|Addr 0x7fd30bf5be90|Src n/a
[engine] opt done SomSet>>contains: |AST 15|Tier 2|Time 28( 26+2 )ms|Inlined 0Y 0N|IR 29/ 29|CodeSize 221|Addr 0x7fd30bf5c310|Src n/a
[engine] opt done SimpleLoop>>counter: |AST 11|Tier 2|Time 29( 26+3 )ms|Inlined 0Y 0N|IR 74/ 88|CodeSize 273|Addr 0x7fd30bf5c710|Src n/a
[engine] opt done Vector>>removeAll |AST 37|Tier 2|Time 65( 58+7 )ms|Inlined 0Y 0N|IR 154/ 327|CodeSize 969|Addr 0x7fd30bf5d010|Src n/a
[engine] opt done ControlFlowGraph>>numNodes |AST 20|Tier 2|Time 50( 46+3 )ms|Inlined 1Y 0N|IR 46/ 128|CodeSize 536|Addr 0x7fd30bf5dc10|Src n/a
[engine] opt done LoopTesterApp>>findLoops: |AST 44|Tier 2|Time 306( 285+21 )ms|Inlined 15Y 1N|IR 344/ 1363|CodeSize 4859|Addr 0x7fd30bf5e290|Src n/a
[engine] opt done HavlakLoopFinder class>>new:lsg: |AST 34|Tier 2|Time 201( 186+15 )ms|Inlined 14Y 0N|IR 273/ 1069|CodeSize 3690|Addr 0x7fd30bf60190|Src n/a
[engine] opt done LoopTesterApp>>buildStraight:n: <split-1136b469> |AST 95|Tier 2|Time 1822( 740+1082)ms|Inlined 29Y 0N|IR 2843/ 9090|CodeSize 43589|Addr 0x7fd30bf61810|Src n/a
[engine] opt done HavlakLoopFinder>>initAllNodes |AST 64|Tier 2|Time 507( 468+39 )ms|Inlined 0Y 2N|IR 566/ 2172|CodeSize 7539|Addr 0x7fd30bf8b390|Src n/a
[engine] opt done BasicBlock>>addOutEdge: |AST 24|Tier 2|Time 199( 137+61 )ms|Inlined 1Y 0N|IR 524/ 1763|CodeSize 7818|Addr 0x7fd30bf8e390|Src n/a
[engine] opt done BasicBlock>>addInEdge: |AST 24|Tier 2|Time 199( 137+63 )ms|Inlined 1Y 0N|IR 524/ 1763|CodeSize 7818|Addr 0x7fd30bf92910|Src n/a
[engine] opt done ControlFlowGraph>>addEdge: |AST 24|Tier 2|Time 289( 131+159 )ms|Inlined 1Y 0N|IR 524/ 1763|CodeSize 7818|Addr 0x7fd30bf96e90|Src n/a
[engine] opt done BasicBlock class>>new: |AST 31|Tier 2|Time 240( 231+9 )ms|Inlined 8Y 0N|IR 76/ 687|CodeSize 2383|Addr 0x7fd30bf9ba10|Src n/a
[engine] opt done HavlakLoopFinder>>findLoops <split-30af7377> |AST 760|Tier 2|Time 4568(2214+2354)ms|Inlined 59Y 7N|IR 9876/35991|CodeSize 156816|Addr 0x7fd30bf9ca10|Src n/a
[engine] opt done HavlakLoopFinder>>initAllNodes <split-15723761> |AST 34|Tier 2|Time 710( 548+162 )ms|Inlined 22Y 0N|IR 1662/ 2889|CodeSize 12745|Addr 0x7fd30bfead90|Src n/a
[engine] opt done SimpleLoop>>nestingLevel: |AST 34|Tier 2|Time 57( 53+4 )ms|Inlined 1Y 0N|IR 158/ 159|CodeSize 381|Addr 0x7fd30bff5d10|Src n/a
[engine] opt done Magnitude>>max: |AST 21|Tier 2|Time 29( 27+2 )ms|Inlined 0Y 0N|IR 29/ 34|CodeSize 206|Addr 0x7fd30bff6790|Src n/a
[engine] opt done LoopTesterApp>>buildStraight:n: <split-1dab9dd6> |AST 95|Tier 2|Time 1721( 573+1148)ms|Inlined 30Y 0N|IR 3070/ 9356|CodeSize 44822|Addr 0x7fd30bff6b90|Src n/a
[engine] opt done LoopTesterApp>>buildStraight:n: <split-247667dd> |AST 95|Tier 2|Time 1703( 591+1112)ms|Inlined 29Y 0N|IR 2843/ 9090|CodeSize 43589|Addr 0x7fd30c022e90|Src n/a
[engine] opt done LoopStructureGraph>>calculateNestingLevelRec:depth: |AST 58|Tier 2|Time 766( 351+415 )ms|Inlined 23Y 1N|IR 1482/ 1950|CodeSize 7514|Addr 0x7fd30c04ca10|Src n/a
[engine] opt done LoopTesterApp>>constructCFG:p:p: |AST 26|Tier 2|Time 511( 397+114 )ms|Inlined 0Y 1N|IR 107/ 481|CodeSize 1748|Addr 0x7fd30c05c310|Src n/a
[engine] opt done LoopStructureGraph>>calculateNestingLevelRec:depth: |AST 85|Tier 2|Time 1254( 363+891 )ms|Inlined 23Y 1N|IR 1645/ 4111|CodeSize 15329|Addr 0x7fd30c05da90|Src n/a
[engine] opt done LoopTesterApp>>buildBaseLoop: <split-75f2099> |AST 181|Tier 2|Time 2566(2160+405 )ms|Inlined 25Y 9N|IR 1351/ 4453|CodeSize 18737|Addr 0x7fd30c070590|Src n/a
[engine] opt done HavlakLoopFinder>>initAllNodes <split-4a699efa> |AST 64|Tier 2|Time 3657(1334+2322)ms|Inlined 76Y 2N|IR 4351/14935|CodeSize 76841|Addr 0x7fd30c07b910|Src n/a
[engine] opt done Integer>>timesRepeat: <split-7fedfe27> |AST 46|Tier 2|Time 614( 576+38 )ms|Inlined 0Y 1N|IR 185/ 1687|CodeSize 5334|Addr 0x7fd30c0bfc10|Src n/a
[engine] opt done Behavior>>new <split-29182679> |AST 26|Tier 2|Time 44( 41+3 )ms|Inlined 0Y 0N|IR 33/ 97|CodeSize 433|Addr 0x7fd30c0c2310|Src n/a
[engine] opt done BasicBlockEdge class>>for:from:to: <split-6d467c87> |AST 37|Tier 2|Time 1297( 559+738 )ms|Inlined 28Y 0N|IR 2917/ 9107|CodeSize 44533|Addr 0x7fd30c0c3210|Src n/a
[engine] opt done BasicBlockEdge>>init:from:to: <split-57bd802b> |AST 96|Tier 2|Time 1096( 615+481 )ms|Inlined 26Y 0N|IR 2888/ 9364|CodeSize 44898|Addr 0x7fd30c0e4910|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-5e742e4> |AST 76|Tier 2|Time 125( 105+20 )ms|Inlined 4Y 0N|IR 370/ 546|CodeSize 2092|Addr 0x7fd30c100290|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-175acfb2> |AST 94|Tier 2|Time 506( 262+244 )ms|Inlined 13Y 0N|IR 787/ 3402|CodeSize 14222|Addr 0x7fd30c103810|Src n/a
[engine] opt done LoopTesterApp>>buildDiamond: <split-1c12f3ee> |AST 157|Tier 2|Time 4659(1697+2962)ms|Inlined 66Y 4N|IR 8891/26180|CodeSize 131084|Addr 0x7fd30c10bd10|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-3703bf3c> |AST 76|Tier 2|Time 129( 109+20 )ms|Inlined 4Y 0N|IR 370/ 546|CodeSize 2092|Addr 0x7fd30c17dc10|Src n/a
[engine] opt done BasicBlockEdge>>init:from:to: <split-55ea2d70> |AST 96|Tier 2|Time 1102( 529+573 )ms|Inlined 25Y 0N|IR 2659/ 8987|CodeSize 42303|Addr 0x7fd30c17f990|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-34cf5a97> |AST 94|Tier 2|Time 402( 268+134 )ms|Inlined 13Y 0N|IR 787/ 3402|CodeSize 14222|Addr 0x7fd30c199990|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-bd2f5a9> |AST 76|Tier 2|Time 125( 105+20 )ms|Inlined 4Y 0N|IR 370/ 546|CodeSize 2092|Addr 0x7fd30c1a1e90|Src n/a
[engine] opt done BasicBlockEdge>>init:from:to: <split-4482469c> |AST 96|Tier 2|Time 960( 503+457 )ms|Inlined 25Y 0N|IR 2659/ 8987|CodeSize 42303|Addr 0x7fd30c1a3c10|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-4d4960c8> |AST 115|Tier 2|Time 475( 333+142 )ms|Inlined 14Y 0N|IR 996/ 3505|CodeSize 15092|Addr 0x7fd30c1bdc10|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-57705d35> |AST 76|Tier 2|Time 126( 105+20 )ms|Inlined 4Y 0N|IR 370/ 546|CodeSize 2092|Addr 0x7fd30c1c7190|Src n/a
[engine] opt done BasicBlockEdge>>init:from:to: <split-60921b21> |AST 96|Tier 2|Time 1082( 544+538 )ms|Inlined 26Y 0N|IR 2888/ 9364|CodeSize 44898|Addr 0x7fd30c1c8f10|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-5dc5c625> |AST 115|Tier 2|Time 431( 290+141 )ms|Inlined 14Y 0N|IR 996/ 3505|CodeSize 15092|Addr 0x7fd30c1e4890|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-27068a50> |AST 115|Tier 2|Time 449( 304+145 )ms|Inlined 14Y 0N|IR 996/ 3505|CodeSize 15092|Addr 0x7fd30c1ee810|Src n/a
[engine] opt done BasicBlockEdge>>init:from:to: <split-6ffc5e28> |AST 96|Tier 2|Time 1072( 567+505 )ms|Inlined 26Y 0N|IR 2888/ 9364|CodeSize 44898|Addr 0x7fd30c1f7d90|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-11653e3b> |AST 115|Tier 2|Time 552( 312+240 )ms|Inlined 14Y 0N|IR 996/ 3505|CodeSize 15092|Addr 0x7fd30c214290|Src n/a
[engine] opt done Behavior>>new <split-6b580b88> |AST 26|Tier 2|Time 44( 42+3 )ms|Inlined 0Y 0N|IR 33/ 97|CodeSize 433|Addr 0x7fd30c21dd90|Src n/a
[engine] opt done BasicBlockEdge class>>for:from:to: <split-773bd77b> |AST 37|Tier 2|Time 1430( 638+792 )ms|Inlined 28Y 0N|IR 2917/ 9107|CodeSize 44533|Addr 0x7fd30c21ff90|Src n/a
[engine] opt done BasicBlockEdge>>init:from:to: <split-6d91790b> |AST 96|Tier 2|Time 1158( 517+641 )ms|Inlined 26Y 0N|IR 2888/ 9364|CodeSize 44898|Addr 0x7fd30c241410|Src n/a
[engine] opt done Behavior>>new <split-a567e72> |AST 26|Tier 2|Time 46( 43+3 )ms|Inlined 0Y 0N|IR 33/ 97|CodeSize 433|Addr 0x7fd30c25cd90|Src n/a
[engine] opt done BasicBlockEdge>>init:from:to: <split-1a5b8489> |AST 96|Tier 2|Time 1053( 504+549 )ms|Inlined 25Y 0N|IR 2659/ 8987|CodeSize 42303|Addr 0x7fd30c25d390|Src n/a
[engine] opt done BasicBlockEdge class>>for:from:to: <split-6ce90bc5> |AST 37|Tier 2|Time 1218( 518+701 )ms|Inlined 27Y 0N|IR 2685/ 8840|CodeSize 41857|Addr 0x7fd30c277390|Src n/a
[engine] opt done Behavior>>new <split-34b9fc7d> |AST 26|Tier 2|Time 45( 42+3 )ms|Inlined 0Y 0N|IR 33/ 97|CodeSize 433|Addr 0x7fd30c297810|Src n/a
[engine] opt done BasicBlockEdge>>init:from:to: <split-27f1bbe0> |AST 96|Tier 2|Time 1060( 494+566 )ms|Inlined 25Y 0N|IR 2659/ 8987|CodeSize 42303|Addr 0x7fd30c298110|Src n/a
[engine] opt done BasicBlockEdge class>>for:from:to: <split-72805168> |AST 37|Tier 2|Time 1221( 517+704 )ms|Inlined 27Y 0N|IR 2685/ 8840|CodeSize 41857|Addr 0x7fd30c2b2110|Src n/a
[engine] opt done Behavior>>new <split-2d84cb86> |AST 26|Tier 2|Time 44( 41+3 )ms|Inlined 0Y 0N|IR 33/ 97|CodeSize 433|Addr 0x7fd30c2d2290|Src n/a
[engine] opt done LoopTesterApp>>buildDiamond: <split-7808fb9> |AST 157|Tier 2|Time 4581(1855+2726)ms|Inlined 66Y 3N|IR 8762/25670|CodeSize 128866|Addr 0x7fd30c2d2c10|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-4b1abd11> |AST 76|Tier 2|Time 134( 114+20 )ms|Inlined 4Y 0N|IR 370/ 546|CodeSize 2092|Addr 0x7fd30c343290|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-3f36b447> |AST 76|Tier 2|Time 135( 115+20 )ms|Inlined 4Y 0N|IR 370/ 546|CodeSize 2092|Addr 0x7fd30c345010|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-332f25c8> |AST 76|Tier 2|Time 130( 109+20 )ms|Inlined 4Y 0N|IR 370/ 546|CodeSize 2092|Addr 0x7fd30c346d90|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-1b32cd16> |AST 76|Tier 2|Time 202( 181+20 )ms|Inlined 4Y 0N|IR 370/ 546|CodeSize 2092|Addr 0x7fd30c349f10|Src n/a
[engine] opt done BasicBlockEdge>>init:from:to: <split-695a69a1> |AST 96|Tier 2|Time 766( 465+301 )ms|Inlined 16Y 0N|IR 2265/ 6131|CodeSize 28656|Addr 0x7fd30c34bc90|Src n/a
[engine] opt done BasicBlockEdge>>init:from:to: <split-4a1c0752> |AST 96|Tier 2|Time 740( 443+297 )ms|Inlined 16Y 0N|IR 2265/ 6131|CodeSize 28656|Addr 0x7fd30c35dd90|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-7c211fd0> |AST 94|Tier 2|Time 393( 259+134 )ms|Inlined 13Y 0N|IR 787/ 3402|CodeSize 14222|Addr 0x7fd30c370290|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-847f3e7> |AST 76|Tier 2|Time 131( 110+20 )ms|Inlined 4Y 0N|IR 370/ 546|CodeSize 2092|Addr 0x7fd30c378e10|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-69cac930> |AST 76|Tier 2|Time 125( 104+20 )ms|Inlined 4Y 0N|IR 370/ 546|CodeSize 2092|Addr 0x7fd30c37ab90|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-47c64cfe> |AST 115|Tier 2|Time 444( 299+145 )ms|Inlined 14Y 0N|IR 996/ 3505|CodeSize 15092|Addr 0x7fd30c37c910|Src n/a
[engine] opt done SimpleLoop class>>basicBlock:reducible: <split-afb5821> |AST 34|Tier 2|Time 324( 291+33 )ms|Inlined 14Y 0N|IR 523/ 1565|CodeSize 5677|Addr 0x7fd30c385e90|Src n/a
[engine] opt done BasicBlockEdge>>init:from:to: <split-264c5d07> |AST 96|Tier 2|Time 732( 370+362 )ms|Inlined 16Y 0N|IR 2265/ 6131|CodeSize 28656|Addr 0x7fd30c388890|Src n/a
[engine] opt done LoopStructureGraph>>initialize |AST 113|Tier 2|Time 548( 427+120 )ms|Inlined 23Y 0N|IR 1340/ 3925|CodeSize 15409|Addr 0x7fd30c39a990|Src n/a
[engine] opt done LoopTesterApp>>buildConnect:end: <split-6f0c74a4> |AST 31|Tier 2|Time 1033( 412+621 )ms|Inlined 19Y 0N|IR 2356/ 6039|CodeSize 26796|Addr 0x7fd30c3a3510|Src n/a
[engine] opt done BasicBlockEdge class>>for:from:to: <split-aeac777> |AST 37|Tier 2|Time 946( 420+525 )ms|Inlined 18Y 0N|IR 2296/ 5984|CodeSize 27047|Addr 0x7fd30c3bce10|Src n/a
[engine] opt done Behavior>>new <split-1d4664d7> |AST 28|Tier 2|Time 465( 385+79 )ms|Inlined 24Y 0N|IR 925/ 2541|CodeSize 7811|Addr 0x7fd30c3d3490|Src n/a
[engine] opt done LoopStructureGraph class>>new |AST 26|Tier 2|Time 800( 633+167 )ms|Inlined 49Y 0N|IR 1668/ 4513|CodeSize 15876|Addr 0x7fd30c3d7c10|Src n/a
[engine] opt done LoopTesterApp>>main:loop:p:p:p: |AST 31|Tier 2|Time 1383( 934+449 )ms|Inlined 66Y 1N|IR 2026/ 5861|CodeSize 23132|Addr 0x7fd30c3e0310|Src n/a
[engine] opt done Integer>>timesRepeat: <split-458544e0> |AST 46|Tier 2|Time 1786(1005+780 )ms|Inlined 67Y 1N|IR 2148/10522|CodeSize 39938|Addr 0x7fd30c3ebd10|Src n/a
[engine] opt done LoopTesterApp>>constructCFG:p:p: <split-6a1e63e3> |AST 106|Tier 2|Time 5701(2231+3470)ms|Inlined 71Y 3N|IR 8637/26138|CodeSize 127158|Addr 0x7fd30c400310|Src n/a
[engine] opt done HavlakLoopFinder>>initAllNodes <split-32fd5cd1> |AST 64|Tier 2|Time 3799(1358+2441)ms|Inlined 88Y 3N|IR 5594/17901|CodeSize 92897|Addr 0x7fd30c476790|Src n/a
[engine] opt done Integer>>timesRepeat: <split-2d66530f> |AST 46|Tier 2|Time 719( 664+55 )ms|Inlined 0Y 1N|IR 192/ 1707|CodeSize 5422|Addr 0x7fd30c4cca90|Src n/a
[engine] opt done ControlFlowGraph>>createNode: <split-2f1a253a> |AST 115|Tier 2|Time 498( 335+163 )ms|Inlined 14Y 0N|IR 982/ 3540|CodeSize 15491|Addr 0x7fd30c4cf210|Src n/a
[engine] opt done LoopTesterApp>>buildConnect:end: <split-16bac21a> |AST 31|Tier 2|Time 1132( 493+638 )ms|Inlined 19Y 0N|IR 2356/ 6039|CodeSize 26796|Addr 0x7fd30c4dad10|Src n/a
[engine] opt done LoopTesterApp>>buildConnect:end: <split-3ad72cfe> |AST 31|Tier 2|Time 1100( 433+667 )ms|Inlined 19Y 0N|IR 2356/ 6039|CodeSize 26796|Addr 0x7fd30c4f4610|Src n/a
[engine] opt done BasicBlockEdge class>>for:from:to: <split-10e35d36> |AST 37|Tier 2|Time 967( 406+561 )ms|Inlined 18Y 0N|IR 2296/ 5984|CodeSize 27047|Addr 0x7fd30c50df10|Src n/a
[engine] opt done LoopTesterApp>>constructCFG:p:p: <split-50c94974> |AST 115|Tier 2|Time 3741(1836+1905)ms|Inlined 55Y 1N|IR 6023/21034|CodeSize 86985|Addr 0x7fd30c524910|Src n/a
[engine] opt done String class>>new: |AST 51|Tier 2|Time 160( 140+19 )ms|Inlined 2Y 1N|IR 213/ 472|CodeSize 1899|Addr 0x7fd30c56b110|Src n/a
[engine] opt done SmallInteger>>printString |AST 152|Tier 2|Time 233( 213+20 )ms|Inlined 4Y 1N|IR 312/ 383|CodeSize 1330|Addr 0x7fd30c56c210|Src n/a
[engine] opt done ControlFlowGraph>>initialize |AST 38|Tier 2|Time 222( 205+17 )ms|Inlined 8Y 0N|IR 129/ 750|CodeSize 2292|Addr 0x7fd30c579110|Src n/a
[engine] opt done SequenceableCollection>>copyReplaceFrom:to:with: |AST 177|Tier 2|Time 269( 233+36 )ms|Inlined 3Y 1N|IR 474/ 1035|CodeSize 4845|Addr 0x7fd30c57c390|Src n/a
[engine] Truffle runtime statistics for engine 2
Compilations : 220
Success : 214
Temporary Bailouts : 4
org.graalvm.compiler.core.common.CancellationBailoutException: Compilation cancelled.: 3
org.graalvm.compiler.core.common.RetryableBailoutException: Assumption invalidated while compiling code: Object[Instance<org.graalvm.compiler.truffle.runtime.OptimizedAssumption>]: 1
Permanent Bailouts : 0
Failed : 0
Interrupted : 2
Invalidated : 21
null : 17
Latest layout assumption Layout no longer valid: 2
Queues : 377
Dequeues : 182
Target inlined into only caller : 164
null : 17
Split call node : 1
Splits : 654
Compilation Accuracy : 0.904545
Queue Accuracy : 0.517241
Compilation Utilization : 0.534531
Remaining Compilation Queue : 0
Time to queue : count= 377, sum= 6361407, min= 4, average= 16873.76, max= 290486 (milliseconds), maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Time waiting in queue : count= 220, sum= 1527489, min= 0, average= 6943.14, max= 26033 (milliseconds), maxTarget=HavlakLoopFinder>>stepEProcessNonBackPreds:nodePool:workList:x:
Time for compilation : count= 218, sum= 155720, min= 23, average= 714.32, max= 5701 (milliseconds), maxTarget=LoopTesterApp>>constructCFG:p:p:
Truffle Tier : count= 214, sum= 77824, min= 20, average= 363.67, max= 2242 (milliseconds), maxTarget=HavlakLoopFinder>>findLoops
Graal Tier : count= 214, sum= 51356, min= 1, average= 239.99, max= 2633 (milliseconds), maxTarget=HavlakLoopFinder>>findLoops
Code Installation : count= 214, sum= 24286, min= 1, average= 113.49, max= 1221 (milliseconds), maxTarget=LoopTesterApp>>constructCFG:p:p:
Truffle node count : count= 218, sum= 262564, min= 12, average= 1204.42, max= 7460, maxTarget=HavlakLoopFinder>>initAllNodes
Trivial : count= 218, sum= 100416, min= 4, average= 460.62, max= 2819, maxTarget=LoopTesterApp>>buildDiamond:
Non Trivial : count= 218, sum= 162148, min= 8, average= 743.80, max= 4716, maxTarget=HavlakLoopFinder>>initAllNodes
Monomorphic : count= 218, sum= 159506, min= 8, average= 731.68, max= 4677, maxTarget=HavlakLoopFinder>>initAllNodes
Polymorphic : count= 218, sum= 2642, min= 0, average= 12.12, max= 101, maxTarget=LoopTesterApp>>buildDiamond:
Megamorphic : count= 218, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Behavior>>new
Truffle call count : count= 218, sum= 3007, min= 0, average= 13.79, max= 91, maxTarget=HavlakLoopFinder>>initAllNodes
Indirect : count= 218, sum= 1, min= 0, average= 0.00, max= 1, maxTarget=Integer>>timesRepeat:
Direct : count= 218, sum= 3006, min= 0, average= 13.79, max= 91, maxTarget=HavlakLoopFinder>>initAllNodes
Dispatched : count= 218, sum= 85, min= 0, average= 0.39, max= 11, maxTarget=HavlakLoopFinder>>findLoops
Inlined : count= 218, sum= 2921, min= 0, average= 13.40, max= 88, maxTarget=HavlakLoopFinder>>initAllNodes
---------- :
Cloned : count= 218, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Behavior>>new
Not Cloned : count= 218, sum= 3012, min= 0, average= 13.82, max= 91, maxTarget=HavlakLoopFinder>>initAllNodes
Truffle loops : count= 218, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Behavior>>new
Graal node count :
After Truffle Tier : count= 218, sum= 297430, min= 5, average= 1364.36, max= 11412, maxTarget=HavlakLoopFinder>>findLoops
After Graal Tier : count= 215, sum= 932044, min= 5, average= 4335.09, max= 41700, maxTarget=HavlakLoopFinder>>findLoops
Graal compilation result :
Code size : count= 214, sum= 4164260, min= 120, average= 19459.16, max= 178109, maxTarget=HavlakLoopFinder>>findLoops
Total frame size : count= 214, sum= 68432, min= 32, average= 319.78, max= 1840, maxTarget=LoopTesterApp>>buildDiamond:
Exception handlers : count= 214, sum= 137, min= 0, average= 0.64, max= 17, maxTarget=HavlakLoopFinder>>initAllNodes
Infopoints : count= 214, sum= 37029, min= 4, average= 173.03, max= 1547, maxTarget=HavlakLoopFinder>>findLoops
CALL : count= 214, sum= 28662, min= 4, average= 133.93, max= 1239, maxTarget=HavlakLoopFinder>>findLoops
IMPLICIT_EXCEPTION : count= 214, sum= 7507, min= 0, average= 35.08, max= 289, maxTarget=HavlakLoopFinder>>findLoops
SAFEPOINT : count= 214, sum= 860, min= 0, average= 4.02, max= 27, maxTarget=LoopTesterApp>>buildDiamond:
Marks : count= 214, sum= 2593, min= 5, average= 12.12, max= 42, maxTarget=HavlakLoopFinder>>findLoops
Data references : count= 214, sum= 28420, min= 0, average= 132.80, max= 1081, maxTarget=HavlakLoopFinder>>findLoops
Raw
5d99b29f-Json.trace.log
# Json (iterations: 250, problem size: 100) on Thu May 27 21:34:15 UTC 2021
# `/home/fniephaus/bin/graalvm-ee-java11-21.1.0/bin/trufflesqueak --experimental-options --smalltalk.disable-startup --smalltalk.disable-interrupts --engine.Mode=default --engine.MultiTier=false --engine.TraceCompilation --engine.CompilationStatistics --log.file="/home/fniephaus/dev/are-we-fast-yet/traces/Json.trace.log" --quiet --code "FileStream startUp: true. Harness new run: #(nil 'Json' 250 100)" /home/fniephaus/dev/are-we-fast-yet/benchmarks/Smalltalk/AWFY64-sista-fbc.image`
[engine] opt done SequenceableCollection>>atAllPut: |AST 72|Tier 2|Time 209( 177+32 )ms|Inlined 0Y 0N|IR 184/ 407|CodeSize 1641|Addr 0x7fcdff8f0d90|Src n/a
[engine] opt done String class>>new: |AST 51|Tier 2|Time 191( 174+17 )ms|Inlined 2Y 1N|IR 213/ 526|CodeSize 1925|Addr 0x7fcdff8fdd90|Src n/a
[engine] opt done Character>>asString |AST 22|Tier 2|Time 251( 241+10 )ms|Inlined 4Y 1N|IR 191/ 259|CodeSize 920|Addr 0x7fcdff908e90|Src n/a
[engine] opt done String>>compareWith: <split-6719a5b8> |AST 25|Tier 2|Time 99( 90+9 )ms|Inlined 2Y 0N|IR 205/ 247|CodeSize 624|Addr 0x7fcdff924990|Src n/a
[engine] opt done String>>= <split-2e1792e7> |AST 69|Tier 2|Time 173( 158+15 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdff926c10|Src n/a
[engine] opt done String>>= <split-6bff19ff> |AST 48|Tier 2|Time 66( 62+4 )ms|Inlined 0Y 0N|IR 43/ 72|CodeSize 381|Addr 0x7fcdff932990|Src n/a
[engine] opt done Vector>>append: |AST 163|Tier 2|Time 188( 142+46 )ms|Inlined 0Y 0N|IR 456/ 1671|CodeSize 7519|Addr 0x7fcdff93b910|Src n/a
[engine] opt deopt Vector>>append: |AST 163|Src n/a
[engine] opt done JsonParser>>readStringInternal |AST 111|Tier 2|Time 1089( 936+153 )ms|Inlined 36Y 4N|IR 2128/ 2851|CodeSize 10085|Addr 0x7fcdff950510|Src n/a
[engine] opt done String>>compareWith:collated: <split-516ebdf8> |AST 33|Tier 2|Time 73( 66+7 )ms|Inlined 1Y 0N|IR 171/ 213|CodeSize 607|Addr 0x7fcdff959d90|Src n/a
[engine] opt done SequenceableCollection>>copyFrom:to: <split-3eba57a7> |AST 68|Tier 2|Time 152( 129+23 )ms|Inlined 3Y 1N|IR 325/ 831|CodeSize 3402|Addr 0x7fcdff95b790|Src n/a
[engine] opt done String>>compare:with:collated: <split-4d8539de> |AST 51|Tier 2|Time 68( 61+6 )ms|Inlined 0Y 0N|IR 137/ 181|CodeSize 607|Addr 0x7fcdff95dc90|Src n/a
[engine] opt done String>>compareWith: <split-5f78de22> |AST 25|Tier 2|Time 76( 68+8 )ms|Inlined 2Y 0N|IR 205/ 247|CodeSize 624|Addr 0x7fcdff960190|Src n/a
[engine] opt done String>>= <split-6a933be2> |AST 69|Tier 2|Time 260( 250+10 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdff963010|Src n/a
[engine] opt done Vector class>>new: |AST 29|Tier 2|Time 85( 79+6 )ms|Inlined 2Y 0N|IR 60/ 319|CodeSize 1095|Addr 0x7fcdff966290|Src n/a
[engine] opt done JsonParser>>readArrayElement: |AST 58|Tier 2|Time 622( 375+247 )ms|Inlined 20Y 1N|IR 1469/ 4631|CodeSize 13736|Addr 0x7fcdff966f10|Src n/a
[engine] opt done String>>= <split-4d6f197e> |AST 69|Tier 2|Time 107( 98+9 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdff970a10|Src n/a
[engine] opt done String>>compareWith: <split-6ef7623> |AST 25|Tier 2|Time 77( 70+8 )ms|Inlined 2Y 0N|IR 205/ 247|CodeSize 624|Addr 0x7fcdff971790|Src n/a
[engine] opt done String>>compare:with:collated: <split-5c089b2f> |AST 51|Tier 2|Time 53( 46+7 )ms|Inlined 0Y 0N|IR 137/ 181|CodeSize 607|Addr 0x7fcdff972610|Src n/a
[engine] opt done String>>compareWith:collated: <split-64e1dd11> |AST 33|Tier 2|Time 71( 64+7 )ms|Inlined 1Y 0N|IR 171/ 213|CodeSize 607|Addr 0x7fcdff972f10|Src n/a
[engine] opt done String>>= <split-6fe46b62> |AST 48|Tier 2|Time 235( 232+3 )ms|Inlined 0Y 0N|IR 43/ 72|CodeSize 381|Addr 0x7fcdff974910|Src n/a
[engine] opt done JsonParser>>readNumber |AST 136|Tier 2|Time 2479(2110+369 )ms|Inlined 67Y 7N|IR 3750/ 3576|CodeSize 9247|Addr 0x7fcdff977c90|Src n/a
[engine] opt done JsonParser>>read <split-4b6ac111> |AST 109|Tier 2|Time 401( 386+15 )ms|Inlined 6Y 1N|IR 431/ 677|CodeSize 2152|Addr 0x7fcdff97fa10|Src n/a
[engine] opt done Behavior>>new <split-5f462e3b> |AST 26|Tier 2|Time 49( 46+3 )ms|Inlined 0Y 0N|IR 33/ 97|CodeSize 433|Addr 0x7fcdff980e10|Src n/a
[engine] opt done Vector>>initialize: |AST 30|Tier 2|Time 62( 56+6 )ms|Inlined 0Y 0N|IR 142/ 292|CodeSize 804|Addr 0x7fcdff981710|Src n/a
[engine] opt inv. Vector>>append: |AST 163|Calls/Thres 17609/ 3|CallsAndLoop/Thres 18209/ 1000|Src n/a
[engine] opt done Vector>>append: |AST 163|Tier 2|Time 172( 121+51 )ms|Inlined 0Y 0N|IR 453/ 1711|CodeSize 7559|Addr 0x7fcdff982490|Src n/a
[engine] opt done String>>= <split-2dce08ff> |AST 48|Tier 2|Time 54( 51+3 )ms|Inlined 0Y 0N|IR 43/ 72|CodeSize 381|Addr 0x7fcdff986e90|Src n/a
[engine] opt done JsonParser>>read <split-6db93db1> |AST 105|Tier 2|Time 211( 197+15 )ms|Inlined 6Y 1N|IR 400/ 564|CodeSize 1792|Addr 0x7fcdff987410|Src n/a
[engine] opt done Behavior>>new <split-305de394> |AST 28|Tier 2|Time 112( 105+6 )ms|Inlined 5Y 0N|IR 63/ 445|CodeSize 1572|Addr 0x7fcdff988810|Src n/a
[engine] opt done JsonArray class>>new |AST 26|Tier 2|Time 157( 151+7 )ms|Inlined 11Y 0N|IR 73/ 445|CodeSize 1572|Addr 0x7fcdff989b90|Src n/a
[engine] opt done JsonParser>>skipWhiteSpace |AST 19|Tier 2|Time 209( 187+22 )ms|Inlined 12Y 0N|IR 650/ 492|CodeSize 1606|Addr 0x7fcdff98d190|Src n/a
[engine] opt done JsonParser>>readChar: |AST 39|Tier 2|Time 409( 254+155 )ms|Inlined 11Y 1N|IR 731/ 889|CodeSize 2815|Addr 0x7fcdff98e890|Src n/a
[engine] opt done String>>= <split-7c9b78e3> |AST 69|Tier 2|Time 105( 96+9 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdff995e90|Src n/a
[engine] opt done String>>= <split-736ac09a> |AST 69|Tier 2|Time 107( 98+9 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdff997610|Src n/a
[engine] opt done String>>= <split-3b0ca5e1> |AST 69|Tier 2|Time 105( 96+9 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdff999290|Src n/a
[engine] opt done String>>= <split-2a037324> |AST 69|Tier 2|Time 106( 97+9 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdff99b090|Src n/a
[engine] opt done JsonParser>>startCapture |AST 12|Tier 2|Time 34( 31+3 )ms|Inlined 0Y 0N|IR 74/ 87|CodeSize 271|Addr 0x7fcdff99c090|Src n/a
[engine] opt done JsonParser>>endCapture |AST 64|Tier 2|Time 281( 210+71 )ms|Inlined 8Y 1N|IR 667/ 1170|CodeSize 4091|Addr 0x7fcdff99c710|Src n/a
[engine] opt done JsonParser>>readArray |AST 135|Tier 2|Time 2018(1619+399 )ms|Inlined 62Y 6N|IR 2902/ 4808|CodeSize 15431|Addr 0x7fcdff9a0410|Src n/a
[engine] opt done JsonParser>>isDigit |AST 196|Tier 2|Time 644( 546+98 )ms|Inlined 40Y 0N|IR 2517/ 1877|CodeSize 2724|Addr 0x7fcdff9ac690|Src n/a
[engine] opt done JsonParser>>readDigit |AST 34|Tier 2|Time 1003( 866+137 )ms|Inlined 48Y 1N|IR 2977/ 2513|CodeSize 4016|Addr 0x7fcdff9b1710|Src n/a
[engine] opt done Vector class>>new |AST 20|Tier 2|Time 275( 270+5 )ms|Inlined 3Y 0N|IR 49/ 290|CodeSize 1040|Addr 0x7fcdff9b8990|Src n/a
[engine] opt done String>>= <split-d02f8d> |AST 69|Tier 2|Time 106( 97+9 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdff9b9d90|Src n/a
[engine] opt done JsonParser>>readRequiredChar: |AST 22|Tier 2|Time 308( 259+49 )ms|Inlined 12Y 1N|IR 768/ 971|CodeSize 2613|Addr 0x7fcdff9bab10|Src n/a
[engine] opt done JsonString class>>new: |AST 31|Tier 2|Time 65( 62+3 )ms|Inlined 2Y 0N|IR 39/ 99|CodeSize 433|Addr 0x7fcdff9bed10|Src n/a
[engine] opt done JsonParser>>readValue |AST 531|Tier 2|Time 2611(1954+657 )ms|Inlined 74Y 28N|IR 5279/ 8114|CodeSize 24251|Addr 0x7fcdff9bf310|Src n/a
[engine] opt done JsonArray>>initialize |AST 22|Tier 2|Time 101( 95+7 )ms|Inlined 4Y 0N|IR 95/ 433|CodeSize 1305|Addr 0x7fcdff9d3d10|Src n/a
[engine] opt done HashIndexTable>>initialize |AST 26|Tier 2|Time 140( 112+27 )ms|Inlined 2Y 0N|IR 274/ 534|CodeSize 1577|Addr 0x7fcdff9d4990|Src n/a
[engine] opt done HashIndexTable>>stringHash: |AST 21|Tier 2|Time 43( 40+3 )ms|Inlined 0Y 0N|IR 32/ 108|CodeSize 467|Addr 0x7fcdff9d6b90|Src n/a
[engine] opt done HashIndexTable>>hashSlotFor: |AST 52|Tier 2|Time 80( 75+4 )ms|Inlined 1Y 0N|IR 60/ 167|CodeSize 714|Addr 0x7fcdff9d7190|Src n/a
[engine] opt done String>>= <split-1136b469> |AST 69|Tier 2|Time 189( 179+10 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdff9d7c10|Src n/a
[engine] opt done Vector>>size |AST 18|Tier 2|Time 33( 30+3 )ms|Inlined 0Y 0N|IR 32/ 110|CodeSize 451|Addr 0x7fcdff9d8d90|Src n/a
[engine] opt done JsonParser>>readName |AST 35|Tier 2|Time 985( 785+200 )ms|Inlined 41Y 4N|IR 2410/ 3086|CodeSize 10475|Addr 0x7fcdff9d9590|Src n/a
[engine] opt done JsonObject>>add:with: |AST 98|Tier 2|Time 601( 245+356 )ms|Inlined 6Y 0N|IR 1133/ 3571|CodeSize 16720|Addr 0x7fcdff9e3b10|Src n/a
[engine] opt done JsonParser>>readObjectKeyValuePair: |AST 117|Tier 2|Time 2591(1781+810 )ms|Inlined 94Y 6N|IR 5951/ 9649|CodeSize 35986|Addr 0x7fcdff9f5f90|Src n/a
[engine] opt done JsonParser>>readNull |AST 78|Tier 2|Time 1038( 924+114 )ms|Inlined 47Y 4N|IR 2427/ 2530|CodeSize 7091|Addr 0x7fcdffa0fd90|Src n/a
[engine] opt done String>>= <split-57bd802b> |AST 69|Tier 2|Time 107( 98+9 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdffa17590|Src n/a
[engine] opt done HashIndexTable class>>new |AST 26|Tier 2|Time 234( 168+66 )ms|Inlined 7Y 0N|IR 529/ 1015|CodeSize 2761|Addr 0x7fcdffa21390|Src n/a
[engine] opt done JsonObject>>initialize |AST 54|Tier 2|Time 330( 240+90 )ms|Inlined 16Y 0N|IR 663/ 1786|CodeSize 5551|Addr 0x7fcdffa25710|Src n/a
[engine] opt done JsonParser>>readObject |AST 130|Tier 2|Time 2680(2290+390 )ms|Inlined 78Y 7N|IR 3593/ 5387|CodeSize 15613|Addr 0x7fcdffa2b190|Src n/a
[engine] opt done String>>= <split-ddf20fd> |AST 69|Tier 2|Time 104( 95+9 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdffa38b10|Src n/a
[engine] opt done String>>= <split-3f36b447> |AST 69|Tier 2|Time 214( 204+9 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdffa3c790|Src n/a
[engine] opt done String>>compareWith:collated: <split-4a03bb68> |AST 33|Tier 2|Time 77( 69+7 )ms|Inlined 1Y 0N|IR 171/ 213|CodeSize 607|Addr 0x7fcdffa41490|Src n/a
[engine] opt done String>>compareWith: <split-175acfb2> |AST 25|Tier 2|Time 85( 77+8 )ms|Inlined 2Y 0N|IR 205/ 247|CodeSize 624|Addr 0x7fcdffa41f10|Src n/a
[engine] opt done String>>= <split-5e742e4> |AST 69|Tier 2|Time 119( 109+9 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdffa43710|Src n/a
[engine] opt done String>>compareWith: <split-71c905a3> |AST 25|Tier 2|Time 81( 73+8 )ms|Inlined 2Y 0N|IR 205/ 247|CodeSize 624|Addr 0x7fcdffa44790|Src n/a
[engine] opt done String>>= <split-59ab43ad> |AST 69|Tier 2|Time 114( 105+9 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdffa45390|Src n/a
[engine] opt done String>>compareWith: <split-1dab9dd6> |AST 25|Tier 2|Time 83( 76+8 )ms|Inlined 2Y 0N|IR 205/ 247|CodeSize 624|Addr 0x7fcdffa4a810|Src n/a
[engine] opt done String>>= <split-7710e2ab> |AST 69|Tier 2|Time 112( 103+9 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdffa4b410|Src n/a
[engine] opt done String>>compareWith: <split-afb5821> |AST 25|Tier 2|Time 83( 75+8 )ms|Inlined 2Y 0N|IR 205/ 247|CodeSize 624|Addr 0x7fcdffa4c190|Src n/a
[engine] opt done String>>= <split-602371d9> |AST 69|Tier 2|Time 118( 108+9 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdffa4d190|Src n/a
[engine] opt done String>>= <split-2f879bab> |AST 48|Tier 2|Time 61( 58+3 )ms|Inlined 0Y 0N|IR 43/ 72|CodeSize 381|Addr 0x7fcdffa4df10|Src n/a
[engine] opt done JsonLiteral class>>TRUE |AST 10|Tier 2|Time 38( 36+2 )ms|Inlined 0Y 0N|IR 21/ 27|CodeSize 230|Addr 0x7fcdffa4e490|Src n/a
[engine] opt done JsonParser>>read <split-7fedfe27> |AST 105|Tier 2|Time 226( 213+13 )ms|Inlined 6Y 1N|IR 400/ 564|CodeSize 1792|Addr 0x7fcdffa4ec10|Src n/a
[engine] opt done String>>= <split-1f25d52f> |AST 69|Tier 2|Time 126( 116+10 )ms|Inlined 3Y 0N|IR 259/ 272|CodeSize 596|Addr 0x7fcdffa4fd10|Src n/a
[engine] opt done Vector>>at: |AST 39|Tier 2|Time 59( 55+4 )ms|Inlined 0Y 0N|IR 69/ 101|CodeSize 514|Addr 0x7fcdffa50a90|Src n/a
[engine] opt done Object>>= |AST 14|Tier 2|Time 41( 36+4 )ms|Inlined 0Y 0N|IR 76/ 131|CodeSize 513|Addr 0x7fcdffa51110|Src n/a
[engine] opt done JsonParser>>read <split-2d66530f> |AST 105|Tier 2|Time 298( 285+13 )ms|Inlined 6Y 1N|IR 400/ 564|CodeSize 1792|Addr 0x7fcdffa53f90|Src n/a
[engine] opt done JsonLiteral class>>FALSE |AST 10|Tier 2|Time 26( 25+2 )ms|Inlined 0Y 0N|IR 21/ 27|CodeSize 230|Addr 0x7fcdffa55410|Src n/a
[engine] opt done JsonParser>>readTrue |AST 78|Tier 2|Time 1005( 883+122 )ms|Inlined 47Y 4N|IR 2428/ 2562|CodeSize 7037|Addr 0x7fcdffa55e10|Src n/a
[engine] opt done JsonObject>>at: |AST 60|Tier 2|Time 250( 204+47 )ms|Inlined 10Y 0N|IR 543/ 617|CodeSize 1867|Addr 0x7fcdffa5ba10|Src n/a
[engine] opt done JsonParser>>readFalse |AST 93|Tier 2|Time 1210(1040+170 )ms|Inlined 58Y 5N|IR 3063/ 3163|CodeSize 8306|Addr 0x7fcdffa5e190|Src n/a
[engine] opt done Json class>>RapBenchmarkMinified |AST 8|Tier 2|Time 26( 24+2 )ms|Inlined 0Y 0N|IR 17/ 18|CodeSize 179|Addr 0x7fcdffa66610|Src n/a
[engine] opt done JsonParser class>>with: |AST 31|Tier 2|Time 100( 93+7 )ms|Inlined 2Y 0N|IR 186/ 374|CodeSize 1299|Addr 0x7fcdffa66a10|Src n/a
[engine] opt done JsonParser>>parse |AST 82|Tier 2|Time 638( 526+112 )ms|Inlined 23Y 2N|IR 1821/ 3794|CodeSize 11628|Addr 0x7fcdffa67b90|Src n/a
[engine] opt done Json>>benchmark |AST 44|Tier 2|Time 808( 550+258 )ms|Inlined 28Y 2N|IR 1528/ 3275|CodeSize 10463|Addr 0x7fcdffa6d190|Src n/a
[engine] opt done JsonArray>>size |AST 20|Tier 2|Time 53( 50+4 )ms|Inlined 1Y 0N|IR 46/ 128|CodeSize 536|Addr 0x7fcdffa72510|Src n/a
[engine] opt done Json>>verifyResult: |AST 126|Tier 2|Time 676( 541+134 )ms|Inlined 35Y 0N|IR 1534/ 1269|CodeSize 3432|Addr 0x7fcdffa72b90|Src n/a
[engine] opt done Benchmark>>innerBenchmarkLoop: |AST 59|Tier 2|Time 1697(1037+660 )ms|Inlined 65Y 2N|IR 3151/ 6182|CodeSize 20644|Addr 0x7fcdffa77390|Src n/a
[engine] opt done SmallInteger>>printString |AST 152|Tier 2|Time 281( 257+23 )ms|Inlined 4Y 1N|IR 361/ 419|CodeSize 1240|Addr 0x7fcdffa8df10|Src n/a
[engine] opt done SequenceableCollection>>copyReplaceFrom:to:with: |AST 177|Tier 2|Time 305( 249+55 )ms|Inlined 3Y 1N|IR 474/ 1460|CodeSize 6553|Addr 0x7fcdffa91e10|Src n/a
[engine] Truffle runtime statistics for engine 2
Compilations : 106
Success : 90
Temporary Bailouts : 3
org.graalvm.compiler.core.common.CancellationBailoutException: Compilation cancelled.: 3
Permanent Bailouts : 0
Failed : 0
Interrupted : 13
Invalidated : 1
null : 1
Queues : 342
Dequeues : 252
Target inlined into only caller : 248
Split call node : 3
null : 1
Splits : 459
Compilation Accuracy : 0.990566
Queue Accuracy : 0.263158
Compilation Utilization : 0.522466
Remaining Compilation Queue : 0
Time to queue : count= 342, sum= 1040187, min= 121, average= 3041.48, max= 66743 (milliseconds), maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Time waiting in queue : count= 106, sum= 289700, min= 0, average= 2733.02, max= 7732 (milliseconds), maxTarget=JsonParser>>read
Time for compilation : count= 93, sum= 34924, min= 26, average= 375.53, max= 2680 (milliseconds), maxTarget=JsonParser>>readObject
Truffle Tier : count= 90, sum= 27918, min= 24, average= 310.21, max= 2290 (milliseconds), maxTarget=JsonParser>>readObject
Graal Tier : count= 90, sum= 4841, min= 1, average= 53.79, max= 614 (milliseconds), maxTarget=JsonParser>>readObjectKeyValuePair:
Code Installation : count= 90, sum= 1841, min= 1, average= 20.46, max= 196 (milliseconds), maxTarget=JsonParser>>readObjectKeyValuePair:
Truffle node count : count= 93, sum= 90030, min= 12, average= 968.06, max= 8014, maxTarget=JsonParser>>readObjectKeyValuePair:
Trivial : count= 93, sum= 33405, min= 4, average= 359.19, max= 3001, maxTarget=JsonParser>>readObjectKeyValuePair:
Non Trivial : count= 93, sum= 56625, min= 8, average= 608.87, max= 5013, maxTarget=JsonParser>>readObjectKeyValuePair:
Monomorphic : count= 93, sum= 56068, min= 8, average= 602.88, max= 4967, maxTarget=JsonParser>>readObjectKeyValuePair:
Polymorphic : count= 93, sum= 557, min= 0, average= 5.99, max= 46, maxTarget=JsonParser>>readObjectKeyValuePair:
Megamorphic : count= 93, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=SequenceableCollection>>atAllPut:
Truffle call count : count= 93, sum= 1185, min= 0, average= 12.74, max= 102, maxTarget=JsonParser>>readValue
Indirect : count= 93, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=SequenceableCollection>>atAllPut:
Direct : count= 93, sum= 1185, min= 0, average= 12.74, max= 102, maxTarget=JsonParser>>readValue
Dispatched : count= 93, sum= 95, min= 0, average= 1.02, max= 28, maxTarget=JsonParser>>readValue
Inlined : count= 93, sum= 1090, min= 0, average= 11.72, max= 94, maxTarget=JsonParser>>readObjectKeyValuePair:
---------- :
Cloned : count= 93, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=SequenceableCollection>>atAllPut:
Not Cloned : count= 93, sum= 1185, min= 0, average= 12.74, max= 102, maxTarget=JsonParser>>readValue
Truffle loops : count= 93, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=SequenceableCollection>>atAllPut:
Graal node count :
After Truffle Tier : count= 93, sum= 67706, min= 17, average= 728.02, max= 5951, maxTarget=JsonParser>>readObjectKeyValuePair:
After Graal Tier : count= 90, sum= 101305, min= 18, average= 1125.61, max= 9649, maxTarget=JsonParser>>readObjectKeyValuePair:
Graal compilation result :
Code size : count= 90, sum= 320770, min= 179, average= 3564.11, max= 35986, maxTarget=JsonParser>>readObjectKeyValuePair:
Total frame size : count= 90, sum= 7680, min= 32, average= 85.33, max= 576, maxTarget=JsonParser>>readObjectKeyValuePair:
Exception handlers : count= 90, sum= 38, min= 0, average= 0.42, max= 24, maxTarget=JsonParser>>readValue
Infopoints : count= 90, sum= 3490, min= 4, average= 38.78, max= 303, maxTarget=JsonParser>>readValue
CALL : count= 90, sum= 2653, min= 4, average= 29.48, max= 228, maxTarget=JsonParser>>readValue
IMPLICIT_EXCEPTION : count= 90, sum= 795, min= 0, average= 8.83, max= 74, maxTarget=JsonParser>>readValue
SAFEPOINT : count= 90, sum= 42, min= 0, average= 0.47, max= 8, maxTarget=JsonParser>>readObjectKeyValuePair:
Marks : count= 90, sum= 738, min= 7, average= 8.20, max= 32, maxTarget=JsonParser>>readValue
Data references : count= 90, sum= 3889, min= 2, average= 43.21, max= 303, maxTarget=JsonParser>>readValue
Raw
5d99b29f-List.trace.log
# List (iterations: 250, problem size: 1500) on Thu May 27 21:17:54 UTC 2021
# `/home/fniephaus/bin/graalvm-ee-java11-21.1.0/bin/trufflesqueak --experimental-options --smalltalk.disable-startup --smalltalk.disable-interrupts --engine.Mode=default --engine.MultiTier=false --engine.TraceCompilation --engine.CompilationStatistics --log.file="/home/fniephaus/dev/are-we-fast-yet/traces/List.trace.log" --quiet --code "FileStream startUp: true. Harness new run: #(nil 'List' 250 1500)" /home/fniephaus/dev/are-we-fast-yet/benchmarks/Smalltalk/AWFY64-sista-fbc.image`
[engine] opt done List>>isShorter:than: <split-577f9109> |AST 75|Tier 2|Time 160( 127+33 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f43578f1890|Src n/a
[engine] opt done List>>isShorter:than: <split-779de014> |AST 75|Tier 2|Time 103( 68+35 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f43578f2410|Src n/a
[engine] opt done List>>isShorter:than: <split-757529a4> |AST 75|Tier 2|Time 105( 70+35 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f43578f2f90|Src n/a
[engine] opt done List>>isShorter:than: <split-1450078a> |AST 75|Tier 2|Time 76( 65+11 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357903910|Src n/a
[engine] opt done List>>isShorter:than: <split-3aefae67> |AST 75|Tier 2|Time 78( 65+13 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357904490|Src n/a
[engine] opt done List>>isShorter:than: <split-69c6161d> |AST 75|Tier 2|Time 85( 73+12 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357907410|Src n/a
[engine] opt done List>>isShorter:than: <split-796d3c9f> |AST 72|Tier 2|Time 69( 61+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f435790f390|Src n/a
[engine] opt done List>>isShorter:than: <split-2e1792e7> |AST 75|Tier 2|Time 72( 61+11 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f435790ff90|Src n/a
[engine] opt done List>>isShorter:than: <split-6bff19ff> |AST 75|Tier 2|Time 72( 59+12 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357910e10|Src n/a
[engine] opt done List>>isShorter:than: <split-29a23c3d> |AST 75|Tier 2|Time 67( 57+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357912590|Src n/a
[engine] opt done List>>isShorter:than: <split-41e1455d> |AST 72|Tier 2|Time 65( 55+9 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f4357913110|Src n/a
[engine] opt done List>>isShorter:than: <split-4d6f197e> |AST 75|Tier 2|Time 69( 56+13 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357913a90|Src n/a
[engine] opt done List>>isShorter:than: <split-41477a6d> |AST 75|Tier 2|Time 95( 85+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357919b10|Src n/a
[engine] opt done List>>isShorter:than: <split-534ca02b> |AST 75|Tier 2|Time 93( 82+11 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f435791b010|Src n/a
[engine] opt done List>>isShorter:than: <split-272a179c> |AST 72|Tier 2|Time 85( 77+9 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f435791a690|Src n/a
[engine] opt done List>>isShorter:than: <split-6fe46b62> |AST 72|Tier 2|Time 69( 59+9 )ms|Inlined 0Y 0N|IR 138/ 212|CodeSize 749|Addr 0x7f435791f090|Src n/a
[engine] opt done List>>isShorter:than: <split-a619c2> |AST 72|Tier 2|Time 72( 63+9 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f435791e710|Src n/a
[engine] opt done List>>isShorter:than: <split-61e45f87> |AST 72|Tier 2|Time 68( 59+10 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f4357923190|Src n/a
[engine] opt done List>>isShorter:than: <split-54dcbb9f> |AST 72|Tier 2|Time 60( 53+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f4357929610|Src n/a
[engine] opt done List>>isShorter:than: <split-5bb3131b> |AST 72|Tier 2|Time 63( 55+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f4357928c90|Src n/a
[engine] opt done List>>isShorter:than: <split-3b0ca5e1> |AST 72|Tier 2|Time 65( 57+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f4357929f90|Src n/a
[engine] opt done List>>isShorter:than: <split-69eb86b4> |AST 72|Tier 2|Time 68( 59+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f435792df90|Src n/a
[engine] opt done List>>isShorter:than: <split-516ebdf8> |AST 75|Tier 2|Time 70( 60+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f435792e910|Src n/a
[engine] opt done List>>isShorter:than: <split-bcb09a6> |AST 75|Tier 2|Time 71( 61+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f435792f490|Src n/a
[engine] opt done List>>isShorter:than: <split-7c2a69b4> |AST 72|Tier 2|Time 63( 55+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f4357930010|Src n/a
[engine] opt done List>>isShorter:than: <split-375b5b7f> |AST 72|Tier 2|Time 64( 55+10 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f4357931410|Src n/a
[engine] opt done List>>isShorter:than: <split-1813f3e9> |AST 72|Tier 2|Time 65( 55+10 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f4357932090|Src n/a
[engine] opt done List>>isShorter:than: <split-7c2327fa> |AST 72|Tier 2|Time 64( 55+9 )ms|Inlined 0Y 0N|IR 138/ 212|CodeSize 749|Addr 0x7f4357934a10|Src n/a
[engine] opt done List>>isShorter:than: <split-4e558728> |AST 72|Tier 2|Time 64( 56+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f4357935490|Src n/a
[engine] opt done List>>isShorter:than: <split-c68a5f8> |AST 75|Tier 2|Time 67( 57+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357935e10|Src n/a
[engine] opt done List>>isShorter:than: <split-6ef7623> |AST 75|Tier 2|Time 66( 56+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f435793b110|Src n/a
[engine] opt done List>>isShorter:than: <split-7ed9ae94> |AST 72|Tier 2|Time 66( 57+10 )ms|Inlined 0Y 0N|IR 138/ 212|CodeSize 749|Addr 0x7f435793bc90|Src n/a
[engine] opt done List>>isShorter:than: <split-66908383> |AST 75|Tier 2|Time 68( 56+12 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f435793c710|Src n/a
[engine] opt done List>>isShorter:than: <split-4463d9d3> |AST 72|Tier 2|Time 62( 54+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f435793f610|Src n/a
[engine] opt done List>>isShorter:than: <split-3068b369> |AST 72|Tier 2|Time 65( 57+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f4357940410|Src n/a
[engine] opt done List>>isShorter:than: <split-17ca8b92> |AST 75|Tier 2|Time 67( 57+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357940d90|Src n/a
[engine] opt done List>>isShorter:than: <split-5491f68b> |AST 75|Tier 2|Time 65( 55+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357941c10|Src n/a
[engine] opt done List>>isShorter:than: <split-1ec7d8b3> |AST 75|Tier 2|Time 114( 56+58 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357943310|Src n/a
[engine] opt done List>>isShorter:than: <split-736ac09a> |AST 75|Tier 2|Time 115( 57+58 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357942790|Src n/a
[engine] opt done List>>isShorter:than: <split-74fef3f7> |AST 72|Tier 2|Time 117( 109+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f4357944810|Src n/a
[engine] opt done List>>isShorter:than: <split-2a037324> |AST 72|Tier 2|Time 82( 74+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f4357945a90|Src n/a
[engine] opt done List>>isShorter:than: <split-648ee871> |AST 75|Tier 2|Time 83( 72+11 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357946410|Src n/a
[engine] opt done List>>isShorter:than: <split-585c13de> |AST 75|Tier 2|Time 84( 73+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357949590|Src n/a
[engine] opt done List>>isShorter:than: <split-5c41d037> |AST 75|Tier 2|Time 65( 55+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f435794b310|Src n/a
[engine] opt done List>>isShorter:than: <split-3eb631b8> |AST 75|Tier 2|Time 65( 55+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f435794be90|Src n/a
[engine] opt done List>>isShorter:than: <split-5eccd3b9> |AST 75|Tier 2|Time 65( 55+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f435794ca10|Src n/a
[engine] opt done List>>isShorter:than: <split-2bc12da> |AST 75|Tier 2|Time 66( 56+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f435794d990|Src n/a
[engine] opt done List>>isShorter:than: <split-3122b117> |AST 75|Tier 2|Time 67( 55+12 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f435794e510|Src n/a
[engine] opt done List>>isShorter:than: <split-591fd34d> |AST 72|Tier 2|Time 63( 55+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f4357951790|Src n/a
[engine] opt done List>>isShorter:than: <split-13d186db> |AST 72|Tier 2|Time 70( 56+14 )ms|Inlined 0Y 0N|IR 138/ 212|CodeSize 749|Addr 0x7f4357952110|Src n/a
[engine] opt done List>>isShorter:than: <split-6f6962ba> |AST 72|Tier 2|Time 69( 60+9 )ms|Inlined 0Y 0N|IR 138/ 212|CodeSize 749|Addr 0x7f4357952b90|Src n/a
[engine] opt done List>>isShorter:than: <split-4565a70a> |AST 72|Tier 2|Time 67( 58+9 )ms|Inlined 0Y 0N|IR 138/ 212|CodeSize 749|Addr 0x7f4357953610|Src n/a
[engine] opt done List>>isShorter:than: <split-6ecd665> |AST 72|Tier 2|Time 63( 54+9 )ms|Inlined 0Y 0N|IR 138/ 212|CodeSize 749|Addr 0x7f4357954490|Src n/a
[engine] opt done List>>isShorter:than: <split-7c9b78e3> |AST 75|Tier 2|Time 66( 56+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357954f10|Src n/a
[engine] opt done List>>isShorter:than: <split-45394b31> |AST 72|Tier 2|Time 61( 52+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f4357955a90|Src n/a
[engine] opt done List>>isShorter:than: <split-4d8539de> |AST 75|Tier 2|Time 65( 55+11 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357956410|Src n/a
[engine] opt done List>>isShorter:than: <split-3eba57a7> |AST 75|Tier 2|Time 66( 55+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357956f90|Src n/a
[engine] opt done List>>isShorter:than: <split-67207d8a> |AST 75|Tier 2|Time 67( 56+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357958d10|Src n/a
[engine] opt done List>>isShorter:than: <split-a0a9fa5> |AST 72|Tier 2|Time 62( 54+9 )ms|Inlined 0Y 0N|IR 138/ 212|CodeSize 749|Addr 0x7f4357959b90|Src n/a
[engine] opt done List>>isShorter:than: <split-4d847d32> |AST 75|Tier 2|Time 66( 56+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f435795a610|Src n/a
[engine] opt done List>>isShorter:than: <split-2234078> |AST 75|Tier 2|Time 65( 55+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f435795b410|Src n/a
[engine] opt done List>>isShorter:than: <split-72458efc> |AST 72|Tier 2|Time 64( 56+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f435795c290|Src n/a
[engine] opt done List>>isShorter:than: <split-6d367020> |AST 72|Tier 2|Time 65( 56+9 )ms|Inlined 0Y 0N|IR 138/ 212|CodeSize 749|Addr 0x7f435795cc10|Src n/a
[engine] opt done List>>isShorter:than: <split-36bc415e> |AST 72|Tier 2|Time 63( 55+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f435795df10|Src n/a
[engine] opt done List>>isShorter:than: <split-5ec77191> |AST 75|Tier 2|Time 67( 57+11 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357962a10|Src n/a
[engine] opt done List>>isShorter:than: <split-6719a5b8> |AST 75|Tier 2|Time 65( 55+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f4357963b90|Src n/a
[engine] opt done List>>isShorter:than: <split-6a74d228> |AST 72|Tier 2|Time 61( 52+9 )ms|Inlined 0Y 0N|IR 138/ 212|CodeSize 749|Addr 0x7f4357965f90|Src n/a
[engine] opt done List>>isShorter:than: <split-349d0836> |AST 72|Tier 2|Time 62( 53+9 )ms|Inlined 0Y 0N|IR 138/ 212|CodeSize 749|Addr 0x7f4357967010|Src n/a
[engine] opt done List>>isShorter:than: <split-6a714237> |AST 72|Tier 2|Time 72( 53+19 )ms|Inlined 0Y 0N|IR 138/ 212|CodeSize 749|Addr 0x7f4357968d90|Src n/a
[engine] opt done List>>isShorter:than: <split-3e134896> |AST 72|Tier 2|Time 71( 63+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f435796b310|Src n/a
[engine] opt done List>>isShorter:than: <split-72ba28ee> |AST 72|Tier 2|Time 59( 51+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f435796bc90|Src n/a
[engine] opt done List>>isShorter:than: <split-2e3a5237> |AST 72|Tier 2|Time 60( 52+8 )ms|Inlined 0Y 0N|IR 135/ 202|CodeSize 667|Addr 0x7f435796c610|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-64e1dd11> |AST 135|Tier 2|Time 1199( 782+417 )ms|Inlined 17Y 8N|IR 1996/ 3085|CodeSize 11087|Addr 0x7f4357978090|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-5c089b2f> |AST 135|Tier 2|Time 1363( 779+584 )ms|Inlined 27Y 15N|IR 3254/ 4815|CodeSize 18120|Addr 0x7f4357984310|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: |AST 135|Tier 2|Time 1950(1072+877 )ms|Inlined 33Y 32N|IR 4815/ 7925|CodeSize 31950|Addr 0x7f435799a090|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-6999cd39> |AST 135|Tier 2|Time 531( 365+166 )ms|Inlined 15Y 5N|IR 1640/ 2267|CodeSize 7699|Addr 0x7f43579bd590|Src n/a
[engine] opt done List>>isShorter:than: <split-4b6ac111> |AST 75|Tier 2|Time 60( 50+10 )ms|Inlined 0Y 0N|IR 200/ 234|CodeSize 847|Addr 0x7f43579c5e90|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-69ce2f62> |AST 28|Tier 2|Time 73( 62+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f43579c6a10|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-c9d82f9> |AST 28|Tier 2|Time 72( 61+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f43579c7710|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-5f462e3b> |AST 135|Tier 2|Time 1895(1048+847 )ms|Inlined 23Y 33N|IR 3808/ 6974|CodeSize 29527|Addr 0x7f43579c9d90|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-6f012914> |AST 135|Tier 2|Time 2942(1523+1419)ms|Inlined 41Y 64N|IR 7013/12532|CodeSize 54155|Addr 0x7f43579ef690|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-585ac855> |AST 135|Tier 2|Time 2460(1354+1106)ms|Inlined 31Y 49N|IR 5353/ 9864|CodeSize 42409|Addr 0x7f4357a28e90|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-14bae047> |AST 135|Tier 2|Time 1768(1148+620 )ms|Inlined 31Y 29N|IR 4442/ 7378|CodeSize 29415|Addr 0x7f4357a53b10|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-3b152928> |AST 135|Tier 2|Time 2740(1355+1384)ms|Inlined 41Y 64N|IR 7013/12532|CodeSize 54155|Addr 0x7f4357a87010|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-56781d96> |AST 135|Tier 2|Time 2750(1365+1384)ms|Inlined 41Y 64N|IR 7013/12532|CodeSize 54155|Addr 0x7f4357ac0310|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-5173200b> |AST 135|Tier 2|Time 2902(1508+1394)ms|Inlined 41Y 64N|IR 7013/12532|CodeSize 54155|Addr 0x7f4357af9090|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-5f78de22> |AST 135|Tier 2|Time 464( 411+53 )ms|Inlined 7Y 1N|IR 738/ 1037|CodeSize 2843|Addr 0x7f4357b31f10|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-5bb8f9e2> |AST 135|Tier 2|Time 1359(1033+325 )ms|Inlined 13Y 18N|IR 2196/ 3868|CodeSize 16385|Addr 0x7f4357b35110|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-720653c2> |AST 28|Tier 2|Time 72( 61+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f4357b45b10|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-6a933be2> |AST 135|Tier 2|Time 1770(1062+707 )ms|Inlined 23Y 33N|IR 3808/ 6868|CodeSize 29042|Addr 0x7f4357b46810|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-60baef24> |AST 28|Tier 2|Time 76( 65+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f4357b64c90|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-732bb66d> |AST 135|Tier 2|Time 2673(1251+1422)ms|Inlined 41Y 64N|IR 7013/12532|CodeSize 54155|Addr 0x7f4357b67c10|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-d02f8d> |AST 135|Tier 2|Time 2825(1452+1373)ms|Inlined 41Y 64N|IR 7013/12532|CodeSize 54155|Addr 0x7f4357ba0a10|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-378bd86d> |AST 28|Tier 2|Time 72( 61+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f4357bda090|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-2189e7a7> |AST 28|Tier 2|Time 71( 60+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f4357bdad90|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-69b2f8e5> |AST 28|Tier 2|Time 71( 60+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f4357bdba90|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-61533ae> |AST 135|Tier 2|Time 2722(1347+1375)ms|Inlined 41Y 64N|IR 7013/12532|CodeSize 54155|Addr 0x7f4357bdc790|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-58065f0c> |AST 28|Tier 2|Time 72( 61+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f4357c15290|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-25c5e994> |AST 135|Tier 2|Time 1132( 802+330 )ms|Inlined 15Y 17N|IR 2263/ 3971|CodeSize 16061|Addr 0x7f4357c15f90|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-3605c4d3> |AST 135|Tier 2|Time 236( 185+52 )ms|Inlined 9Y 0N|IR 841/ 897|CodeSize 2221|Addr 0x7f4357c26490|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-599f571f> |AST 28|Tier 2|Time 72( 62+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f4357c29410|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-3d7fa3ae> |AST 135|Tier 2|Time 1333(1008+325 )ms|Inlined 13Y 18N|IR 2196/ 3868|CodeSize 16385|Addr 0x7f4357c2b010|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-77128dab> |AST 135|Tier 2|Time 468( 409+59 )ms|Inlined 7Y 1N|IR 738/ 1213|CodeSize 3540|Addr 0x7f4357c3ba10|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-187eb9a8> |AST 135|Tier 2|Time 1493(1026+467 )ms|Inlined 13Y 18N|IR 2196/ 3868|CodeSize 16385|Addr 0x7f4357c40b90|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-312afbc7> |AST 135|Tier 2|Time 2830(1466+1364)ms|Inlined 41Y 64N|IR 7013/12532|CodeSize 54155|Addr 0x7f4357c51b90|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-726a6b94> |AST 28|Tier 2|Time 70( 60+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f4357c8a690|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-6569dded> |AST 28|Tier 2|Time 74( 63+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f4357c8b390|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-466d49f0> |AST 28|Tier 2|Time 73( 62+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f4357c8c390|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-7b60c3e> |AST 135|Tier 2|Time 2827(1463+1364)ms|Inlined 41Y 64N|IR 7013/12532|CodeSize 54155|Addr 0x7f4357c8d090|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-710d7aff> |AST 28|Tier 2|Time 76( 65+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f4357cc5b90|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-5395ea39> |AST 28|Tier 2|Time 77( 66+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f4357cc6890|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-1517f633> |AST 28|Tier 2|Time 76( 65+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f4357cc7590|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-4fe01803> |AST 28|Tier 2|Time 77( 66+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f4357cc8290|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-65327f5> |AST 28|Tier 2|Time 76( 65+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f4357cc9a90|Src n/a
[engine] opt done Benchmark>>innerBenchmarkLoop: |AST 59|Tier 2|Time 580( 567+13 )ms|Inlined 1Y 1N|IR 136/ 441|CodeSize 1755|Addr 0x7f4357ccdd90|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-503c29ff> |AST 28|Tier 2|Time 73( 62+11 )ms|Inlined 1Y 0N|IR 172/ 257|CodeSize 697|Addr 0x7f4357ccef90|Src n/a
[engine] opt done List>>verifyResult: |AST 15|Tier 2|Time 153( 151+2 )ms|Inlined 0Y 0N|IR 25/ 26|CodeSize 213|Addr 0x7f4357ccfc90|Src n/a
[engine] opt done List>>isShorter:than: <split-30feffc> |AST 72|Tier 2|Time 57( 49+8 )ms|Inlined 0Y 0N|IR 138/ 212|CodeSize 749|Addr 0x7f4357cd0090|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-2d7e1102> |AST 135|Tier 2|Time 2696(1292+1404)ms|Inlined 41Y 64N|IR 7013/12532|CodeSize 54155|Addr 0x7f4357cd1790|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-5449095d> |AST 135|Tier 2|Time 2697(1288+1409)ms|Inlined 41Y 64N|IR 7013/12532|CodeSize 54155|Addr 0x7f4357d0a290|Src n/a
[engine] opt done ListElement class>>new: |AST 31|Tier 2|Time 80( 77+4 )ms|Inlined 2Y 0N|IR 40/ 102|CodeSize 441|Addr 0x7f4357d43110|Src n/a
[engine] opt done ListElement>>next: |AST 11|Tier 2|Time 26( 23+3 )ms|Inlined 0Y 0N|IR 57/ 89|CodeSize 381|Addr 0x7f4357d43790|Src n/a
[engine] opt done List>>makeList: |AST 76|Tier 2|Time 246( 196+51 )ms|Inlined 14Y 1N|IR 378/ 1090|CodeSize 4131|Addr 0x7f4357d43f10|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-28cb9120> |AST 135|Tier 2|Time 2727(1324+1403)ms|Inlined 41Y 64N|IR 7013/12657|CodeSize 54688|Addr 0x7f4357d47e10|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-6ad11a56> |AST 130|Tier 2|Time 1799(1056+743 )ms|Inlined 23Y 33N|IR 3739/ 6930|CodeSize 29637|Addr 0x7f4357d82890|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-522b2631> |AST 135|Tier 2|Time 2857(1323+1534)ms|Inlined 41Y 64N|IR 7013/12624|CodeSize 54682|Addr 0x7f4357da1e90|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-63429932> |AST 135|Tier 2|Time 2739(1339+1400)ms|Inlined 41Y 64N|IR 7013/12624|CodeSize 54634|Addr 0x7f4357ddc990|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-18fdb6cf> |AST 135|Tier 2|Time 2746(1345+1401)ms|Inlined 41Y 64N|IR 7013/12624|CodeSize 54682|Addr 0x7f4357e15a10|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-45f24169> |AST 130|Tier 2|Time 2714(1316+1398)ms|Inlined 41Y 64N|IR 6948/12652|CodeSize 54600|Addr 0x7f4357e51a10|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-6ad5923a> |AST 135|Tier 2|Time 2727(1324+1402)ms|Inlined 41Y 64N|IR 7013/12624|CodeSize 54682|Addr 0x7f4357e94910|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-43b0ade> |AST 130|Tier 2|Time 2723(1333+1391)ms|Inlined 41Y 64N|IR 6948/12619|CodeSize 54594|Addr 0x7f4357eccf90|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-15723761> |AST 135|Tier 2|Time 2678(1317+1361)ms|Inlined 41Y 64N|IR 7013/12624|CodeSize 54682|Addr 0x7f4357f06690|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-3fbfa96> |AST 135|Tier 2|Time 2691(1288+1403)ms|Inlined 41Y 64N|IR 7013/12624|CodeSize 54682|Addr 0x7f4357f3fe90|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-2adddc06> |AST 130|Tier 2|Time 2871(1470+1402)ms|Inlined 41Y 64N|IR 6948/12652|CodeSize 54600|Addr 0x7f4357f78510|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-301d8120> |AST 135|Tier 2|Time 2715(1341+1374)ms|Inlined 41Y 64N|IR 7013/12624|CodeSize 54682|Addr 0x7f4357fb0a10|Src n/a
[engine] opt done ListElement>>length |AST 43|Tier 2|Time 90( 72+18 )ms|Inlined 2Y 1N|IR 321/ 517|CodeSize 1799|Addr 0x7f4357fe9590|Src n/a
[engine] opt done List>>benchmark |AST 76|Tier 2|Time 1343(1112+231 )ms|Inlined 54Y 6N|IR 1619/ 3515|CodeSize 11116|Addr 0x7f4357fec110|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-5a0d3466> |AST 130|Tier 2|Time 2810(1299+1511)ms|Inlined 41Y 64N|IR 6948/12619|CodeSize 54594|Addr 0x7f4357ff9810|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-5cc7be79> |AST 135|Tier 2|Time 2681(1289+1392)ms|Inlined 41Y 64N|IR 7013/12624|CodeSize 54682|Addr 0x7f4358031f10|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-7b44b63d> |AST 130|Tier 2|Time 1057(1013+44 )ms|Inlined 3Y 3N|IR 440/ 1012|CodeSize 3262|Addr 0x7f435806b410|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-4a699efa> |AST 130|Tier 2|Time 2745(1356+1389)ms|Inlined 41Y 64N|IR 6948/12619|CodeSize 54594|Addr 0x7f4358070890|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-38499e48> |AST 130|Tier 2|Time 2735(1340+1394)ms|Inlined 41Y 64N|IR 6948/12619|CodeSize 54594|Addr 0x7f43580a8f90|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-1136b469> |AST 130|Tier 2|Time 668( 616+52 )ms|Inlined 5Y 2N|IR 554/ 1075|CodeSize 3202|Addr 0x7f43580e1690|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-17ae7628> |AST 130|Tier 2|Time 2721(1499+1221)ms|Inlined 41Y 64N|IR 6948/12619|CodeSize 54594|Addr 0x7f43580e4a90|Src n/a
[engine] opt done ListElement>>length <split-6d467c87> |AST 38|Tier 2|Time 88( 71+17 )ms|Inlined 2Y 1N|IR 267/ 500|CodeSize 1653|Addr 0x7f435811d190|Src n/a
[engine] opt done ListElement>>length <split-4917d36b> |AST 43|Tier 2|Time 204( 184+20 )ms|Inlined 2Y 1N|IR 321/ 593|CodeSize 2132|Addr 0x7f435811e590|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-6579c3d9> |AST 130|Tier 2|Time 2647(1256+1390)ms|Inlined 41Y 64N|IR 6948/12619|CodeSize 54594|Addr 0x7f4358120110|Src n/a
[engine] opt done List>>talkWithX:withY:withZ: <split-66434cc8> |AST 130|Tier 2|Time 2653(1263+1390)ms|Inlined 41Y 64N|IR 6948/12619|CodeSize 54594|Addr 0x7f4358158810|Src n/a
[engine] opt done String class>>new: |AST 51|Tier 2|Time 166( 147+18 )ms|Inlined 2Y 1N|IR 213/ 472|CodeSize 1899|Addr 0x7f4358198410|Src n/a
[engine] opt done SmallInteger>>printString |AST 152|Tier 2|Time 243( 220+23 )ms|Inlined 4Y 1N|IR 361/ 443|CodeSize 1368|Addr 0x7f435819b190|Src n/a
[engine] opt done SequenceableCollection>>copyReplaceFrom:to:with: |AST 177|Tier 2|Time 270( 230+40 )ms|Inlined 3Y 1N|IR 474/ 1035|CodeSize 4845|Addr 0x7f43581a1d90|Src n/a
[engine] Truffle runtime statistics for engine 2
Compilations : 154
Success : 151
Temporary Bailouts : 0
Permanent Bailouts : 0
Failed : 0
Interrupted : 3
Invalidated : 0
Queues : 210
Dequeues : 59
Target inlined into only caller : 59
Splits : 353
Compilation Accuracy : 1.000000
Queue Accuracy : 0.719048
Compilation Utilization : 0.826126
Remaining Compilation Queue : 0
Time to queue : count= 210, sum= 954598, min= 48, average= 4545.71, max= 136537 (milliseconds), maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Time waiting in queue : count= 154, sum= 1024944, min= 0, average= 6655.48, max= 32069 (milliseconds), maxTarget=ListElement>>length
Time for compilation : count= 151, sum= 113135, min= 27, average= 749.24, max= 2943 (milliseconds), maxTarget=List>>talkWithX:withY:withZ:
Truffle Tier : count= 151, sum= 63142, min= 23, average= 418.16, max= 1523 (milliseconds), maxTarget=List>>talkWithX:withY:withZ:
Graal Tier : count= 151, sum= 26374, min= 1, average= 174.67, max= 816 (milliseconds), maxTarget=List>>talkWithX:withY:withZ:
Code Installation : count= 151, sum= 23618, min= 1, average= 156.42, max= 793 (milliseconds), maxTarget=List>>talkWithX:withY:withZ:
Truffle node count : count= 151, sum= 257224, min= 17, average= 1703.47, max= 6741, maxTarget=List>>talkWithX:withY:withZ:
Trivial : count= 151, sum= 89357, min= 6, average= 591.77, max= 2331, maxTarget=List>>talkWithX:withY:withZ:
Non Trivial : count= 151, sum= 167867, min= 11, average= 1111.70, max= 4410, maxTarget=List>>talkWithX:withY:withZ:
Monomorphic : count= 151, sum= 162975, min= 11, average= 1079.30, max= 4284, maxTarget=List>>talkWithX:withY:withZ:
Polymorphic : count= 151, sum= 4892, min= 0, average= 32.40, max= 126, maxTarget=List>>talkWithX:withY:withZ:
Megamorphic : count= 151, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=List>>isShorter:than:
Truffle call count : count= 151, sum= 3786, min= 0, average= 25.07, max= 105, maxTarget=List>>talkWithX:withY:withZ:
Indirect : count= 151, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=List>>isShorter:than:
Direct : count= 151, sum= 3786, min= 0, average= 25.07, max= 105, maxTarget=List>>talkWithX:withY:withZ:
Dispatched : count= 151, sum= 2185, min= 0, average= 14.47, max= 64, maxTarget=List>>talkWithX:withY:withZ:
Inlined : count= 151, sum= 1601, min= 0, average= 10.60, max= 54, maxTarget=List>>benchmark
---------- :
Cloned : count= 151, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=List>>isShorter:than:
Not Cloned : count= 151, sum= 3786, min= 0, average= 25.07, max= 105, maxTarget=List>>talkWithX:withY:withZ:
Truffle loops : count= 151, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=List>>isShorter:than:
Graal node count :
After Truffle Tier : count= 151, sum= 267551, min= 25, average= 1771.86, max= 7013, maxTarget=List>>talkWithX:withY:withZ:
After Graal Tier : count= 151, sum= 471764, min= 26, average= 3124.26, max= 12657, maxTarget=List>>talkWithX:withY:withZ:
Graal compilation result :
Code size : count= 151, sum= 1989692, min= 213, average= 13176.77, max= 54688, maxTarget=List>>talkWithX:withY:withZ:
Total frame size : count= 151, sum= 70656, min= 32, average= 467.92, max= 1904, maxTarget=List>>talkWithX:withY:withZ:
Exception handlers : count= 151, sum= 2199, min= 0, average= 14.56, max= 64, maxTarget=List>>talkWithX:withY:withZ:
Infopoints : count= 151, sum= 29153, min= 4, average= 193.07, max= 793, maxTarget=List>>talkWithX:withY:withZ:
CALL : count= 151, sum= 20918, min= 4, average= 138.53, max= 569, maxTarget=List>>talkWithX:withY:withZ:
IMPLICIT_EXCEPTION : count= 151, sum= 7365, min= 0, average= 48.77, max= 203, maxTarget=List>>talkWithX:withY:withZ:
SAFEPOINT : count= 151, sum= 870, min= 0, average= 5.76, max= 21, maxTarget=List>>talkWithX:withY:withZ:
Marks : count= 151, sum= 4222, min= 7, average= 27.96, max= 92, maxTarget=List>>talkWithX:withY:withZ:
Data references : count= 151, sum= 22523, min= 2, average= 149.16, max= 591, maxTarget=List>>talkWithX:withY:withZ:
Raw
5d99b29f-Mandelbrot.trace.log
# Mandelbrot (iterations: 250, problem size: 500) on Thu May 27 21:22:57 UTC 2021
# `/home/fniephaus/bin/graalvm-ee-java11-21.1.0/bin/trufflesqueak --experimental-options --smalltalk.disable-startup --smalltalk.disable-interrupts --engine.Mode=default --engine.MultiTier=false --engine.TraceCompilation --engine.CompilationStatistics --log.file="/home/fniephaus/dev/are-we-fast-yet/traces/Mandelbrot.trace.log" --quiet --code "FileStream startUp: true. Harness new run: #(nil 'Mandelbrot' 250 500)" /home/fniephaus/dev/are-we-fast-yet/benchmarks/Smalltalk/AWFY64-sista-fbc.image`
[engine] opt done Integer>><< |AST 25|Tier 2|Time 94( 79+15 )ms|Inlined 0Y 0N|IR 76/ 112|CodeSize 461|Addr 0x7f9a6f90b290|Src n/a
[engine] opt done Mandelbrot>>mandelbrot: |AST 500|Tier 2|Time 391( 270+121 )ms|Inlined 2Y 0N|IR 550/ 1809|CodeSize 13398|Addr 0x7f9a6f928990|Src n/a
[engine] opt done String class>>new: |AST 51|Tier 2|Time 181( 160+21 )ms|Inlined 2Y 1N|IR 213/ 472|CodeSize 1899|Addr 0x7f9a6f94d390|Src n/a
[engine] opt done SmallInteger>>printString |AST 152|Tier 2|Time 268( 245+22 )ms|Inlined 4Y 1N|IR 361/ 419|CodeSize 1240|Addr 0x7f9a6f954a90|Src n/a
[engine] Truffle runtime statistics for engine 2
Compilations : 6
Success : 4
Temporary Bailouts : 0
Permanent Bailouts : 0
Failed : 0
Interrupted : 2
Invalidated : 0
Queues : 6
Dequeues : 0
Splits : 191
Compilation Accuracy : 1.000000
Queue Accuracy : 1.000000
Compilation Utilization : 0.008507
Remaining Compilation Queue : 0
Time to queue : count= 6, sum= 413228, min= 142, average= 68871.42, max= 111866 (milliseconds), maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Time waiting in queue : count= 6, sum= 49, min= 1, average= 8.23, max= 17 (milliseconds), maxTarget=String class>>new:
Time for compilation : count= 4, sum= 952, min= 105, average= 238.07, max= 393 (milliseconds), maxTarget=Mandelbrot>>mandelbrot:
Truffle Tier : count= 4, sum= 753, min= 78, average= 188.48, max= 269 (milliseconds), maxTarget=Mandelbrot>>mandelbrot:
Graal Tier : count= 4, sum= 129, min= 11, average= 32.25, max= 84 (milliseconds), maxTarget=Mandelbrot>>mandelbrot:
Code Installation : count= 4, sum= 69, min= 6, average= 17.33, max= 39 (milliseconds), maxTarget=Mandelbrot>>mandelbrot:
Truffle node count : count= 4, sum= 1777, min= 40, average= 444.25, max= 892, maxTarget=Mandelbrot>>mandelbrot:
Trivial : count= 4, sum= 687, min= 15, average= 171.75, max= 342, maxTarget=Mandelbrot>>mandelbrot:
Non Trivial : count= 4, sum= 1090, min= 25, average= 272.50, max= 550, maxTarget=Mandelbrot>>mandelbrot:
Monomorphic : count= 4, sum= 1072, min= 25, average= 268.00, max= 550, maxTarget=Mandelbrot>>mandelbrot:
Polymorphic : count= 4, sum= 18, min= 0, average= 4.50, max= 9, maxTarget=String class>>new:
Megamorphic : count= 4, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Integer>><<
Truffle call count : count= 4, sum= 10, min= 0, average= 2.50, max= 5, maxTarget=SmallInteger>>printString
Indirect : count= 4, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Integer>><<
Direct : count= 4, sum= 10, min= 0, average= 2.50, max= 5, maxTarget=SmallInteger>>printString
Dispatched : count= 4, sum= 2, min= 0, average= 0.50, max= 1, maxTarget=String class>>new:
Inlined : count= 4, sum= 8, min= 0, average= 2.00, max= 4, maxTarget=SmallInteger>>printString
---------- :
Cloned : count= 4, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Integer>><<
Not Cloned : count= 4, sum= 10, min= 0, average= 2.50, max= 5, maxTarget=SmallInteger>>printString
Truffle loops : count= 4, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Integer>><<
Graal node count :
After Truffle Tier : count= 4, sum= 1200, min= 76, average= 300.00, max= 550, maxTarget=Mandelbrot>>mandelbrot:
After Graal Tier : count= 4, sum= 2812, min= 112, average= 703.00, max= 1809, maxTarget=Mandelbrot>>mandelbrot:
Graal compilation result :
Code size : count= 4, sum= 16998, min= 461, average= 4249.50, max= 13398, maxTarget=Mandelbrot>>mandelbrot:
Total frame size : count= 4, sum= 784, min= 32, average= 196.00, max= 640, maxTarget=Mandelbrot>>mandelbrot:
Exception handlers : count= 4, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Integer>><<
Infopoints : count= 4, sum= 147, min= 8, average= 36.75, max= 101, maxTarget=Mandelbrot>>mandelbrot:
CALL : count= 4, sum= 110, min= 7, average= 27.50, max= 73, maxTarget=Mandelbrot>>mandelbrot:
IMPLICIT_EXCEPTION : count= 4, sum= 30, min= 1, average= 7.50, max= 22, maxTarget=Mandelbrot>>mandelbrot:
SAFEPOINT : count= 4, sum= 7, min= 0, average= 1.75, max= 6, maxTarget=Mandelbrot>>mandelbrot:
Marks : count= 4, sum= 35, min= 7, average= 8.75, max= 13, maxTarget=Mandelbrot>>mandelbrot:
Data references : count= 4, sum= 155, min= 4, average= 38.75, max= 108, maxTarget=Mandelbrot>>mandelbrot:
Raw
5d99b29f-NBody.trace.log
# NBody (iterations: 250, problem size: 250000) on Thu May 27 21:21:55 UTC 2021
# `/home/fniephaus/bin/graalvm-ee-java11-21.1.0/bin/trufflesqueak --experimental-options --smalltalk.disable-startup --smalltalk.disable-interrupts --engine.Mode=default --engine.MultiTier=false --engine.TraceCompilation --engine.CompilationStatistics --log.file="/home/fniephaus/dev/are-we-fast-yet/traces/NBody.trace.log" --quiet --code "FileStream startUp: true. Harness new run: #(nil 'NBody' 250 250000)" /home/fniephaus/dev/are-we-fast-yet/benchmarks/Smalltalk/AWFY64-sista-fbc.image`
[engine] opt done Body>>vz: |AST 11|Tier 2|Time 121( 100+21 )ms|Inlined 0Y 0N|IR 76/ 91|CodeSize 286|Addr 0x7f087b8f6510|Src n/a
[engine] opt done Body>>vy: |AST 11|Tier 2|Time 121( 97+25 )ms|Inlined 0Y 0N|IR 76/ 91|CodeSize 286|Addr 0x7f087b8f5e90|Src n/a
[engine] opt done Body>>vx: |AST 11|Tier 2|Time 122( 101+21 )ms|Inlined 0Y 0N|IR 76/ 91|CodeSize 286|Addr 0x7f087b8f5810|Src n/a
[engine] opt done NBodySystem>>advance: |AST 187|Tier 2|Time 150( 140+11 )ms|Inlined 3Y 0N|IR 310/ 304|CodeSize 658|Addr 0x7f087b918690|Src n/a
[engine] opt done SequenceableCollection>>do: <split-14bae047> |AST 73|Tier 2|Time 282( 231+52 )ms|Inlined 4Y 0N|IR 493/ 1700|CodeSize 5618|Addr 0x7f087b92c790|Src n/a
[engine] opt done NBodySystem>>advance: |AST 816|Tier 2|Time 716( 579+137 )ms|Inlined 11Y 0N|IR 1341/ 2268|CodeSize 9276|Addr 0x7f087b940510|Src n/a
[engine] opt done NBody>>innerBenchmarkLoop: |AST 95|Tier 2|Time 2780(1854+926 )ms|Inlined 98Y 1N|IR 6158/11947|CodeSize 55373|Addr 0x7f087b96d190|Src n/a
[engine] opt done String class>>new: |AST 51|Tier 2|Time 165( 146+19 )ms|Inlined 2Y 1N|IR 213/ 472|CodeSize 1899|Addr 0x7f087b99e790|Src n/a
[engine] opt done SmallInteger>>printString |AST 152|Tier 2|Time 246( 221+24 )ms|Inlined 4Y 1N|IR 361/ 443|CodeSize 1368|Addr 0x7f087b9a9e90|Src n/a
[engine] opt done SequenceableCollection>>copyReplaceFrom:to:with: |AST 177|Tier 2|Time 278( 239+39 )ms|Inlined 3Y 1N|IR 474/ 1035|CodeSize 4845|Addr 0x7f087b9afc10|Src n/a
[engine] Truffle runtime statistics for engine 2
Compilations : 11
Success : 10
Temporary Bailouts : 0
Permanent Bailouts : 0
Failed : 0
Interrupted : 1
Invalidated : 0
Queues : 14
Dequeues : 3
Target inlined into only caller : 3
Splits : 199
Compilation Accuracy : 1.000000
Queue Accuracy : 0.785714
Compilation Utilization : 0.090229
Remaining Compilation Queue : 0
Time to queue : count= 14, sum= 176536, min= 90, average= 12609.76, max= 55949 (milliseconds), maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Time waiting in queue : count= 11, sum= 219, min= 1, average= 19.98, max= 128 (milliseconds), maxTarget=NBodySystem>>advance:
Time for compilation : count= 10, sum= 5058, min= 140, average= 505.89, max= 2782 (milliseconds), maxTarget=NBody>>innerBenchmarkLoop:
Truffle Tier : count= 10, sum= 3707, min= 96, average= 370.76, max= 1854 (milliseconds), maxTarget=NBody>>innerBenchmarkLoop:
Graal Tier : count= 10, sum= 814, min= 6, average= 81.47, max= 601 (milliseconds), maxTarget=NBody>>innerBenchmarkLoop:
Code Installation : count= 10, sum= 536, min= 4, average= 53.66, max= 326 (milliseconds), maxTarget=NBody>>innerBenchmarkLoop:
Truffle node count : count= 10, sum= 12639, min= 19, average= 1263.90, max= 8572, maxTarget=NBody>>innerBenchmarkLoop:
Trivial : count= 10, sum= 4673, min= 8, average= 467.30, max= 3172, maxTarget=NBody>>innerBenchmarkLoop:
Non Trivial : count= 10, sum= 7966, min= 11, average= 796.60, max= 5400, maxTarget=NBody>>innerBenchmarkLoop:
Monomorphic : count= 10, sum= 7937, min= 11, average= 793.70, max= 5400, maxTarget=NBody>>innerBenchmarkLoop:
Polymorphic : count= 10, sum= 29, min= 0, average= 2.90, max= 11, maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Megamorphic : count= 10, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Body>>vy:
Truffle call count : count= 10, sum= 129, min= 0, average= 12.90, max= 99, maxTarget=NBody>>innerBenchmarkLoop:
Indirect : count= 10, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Body>>vy:
Direct : count= 10, sum= 129, min= 0, average= 12.90, max= 99, maxTarget=NBody>>innerBenchmarkLoop:
Dispatched : count= 10, sum= 4, min= 0, average= 0.40, max= 1, maxTarget=NBody>>innerBenchmarkLoop:
Inlined : count= 10, sum= 125, min= 0, average= 12.50, max= 98, maxTarget=NBody>>innerBenchmarkLoop:
---------- :
Cloned : count= 10, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Body>>vy:
Not Cloned : count= 10, sum= 129, min= 0, average= 12.90, max= 99, maxTarget=NBody>>innerBenchmarkLoop:
Truffle loops : count= 10, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Body>>vy:
Graal node count :
After Truffle Tier : count= 10, sum= 9578, min= 76, average= 957.80, max= 6158, maxTarget=NBody>>innerBenchmarkLoop:
After Graal Tier : count= 10, sum= 18442, min= 91, average= 1844.20, max= 11947, maxTarget=NBody>>innerBenchmarkLoop:
Graal compilation result :
Code size : count= 10, sum= 79895, min= 286, average= 7989.50, max= 55373, maxTarget=NBody>>innerBenchmarkLoop:
Total frame size : count= 10, sum= 1696, min= 32, average= 169.60, max= 656, maxTarget=NBody>>innerBenchmarkLoop:
Exception handlers : count= 10, sum= 1, min= 0, average= 0.10, max= 1, maxTarget=NBody>>innerBenchmarkLoop:
Infopoints : count= 10, sum= 640, min= 5, average= 64.00, max= 385, maxTarget=NBody>>innerBenchmarkLoop:
CALL : count= 10, sum= 482, min= 5, average= 48.20, max= 287, maxTarget=NBody>>innerBenchmarkLoop:
IMPLICIT_EXCEPTION : count= 10, sum= 140, min= 0, average= 14.00, max= 88, maxTarget=NBody>>innerBenchmarkLoop:
SAFEPOINT : count= 10, sum= 18, min= 0, average= 1.80, max= 10, maxTarget=NBody>>innerBenchmarkLoop:
Marks : count= 10, sum= 93, min= 7, average= 9.30, max= 18, maxTarget=NBody>>innerBenchmarkLoop:
Data references : count= 10, sum= 1618, min= 2, average= 161.80, max= 1384, maxTarget=NBody>>innerBenchmarkLoop:
Raw
5d99b29f-Permute.trace.log
# Permute (iterations: 250, problem size: 1000) on Thu May 27 21:33:14 UTC 2021
# `/home/fniephaus/bin/graalvm-ee-java11-21.1.0/bin/trufflesqueak --experimental-options --smalltalk.disable-startup --smalltalk.disable-interrupts --engine.Mode=default --engine.MultiTier=false --engine.TraceCompilation --engine.CompilationStatistics --log.file="/home/fniephaus/dev/are-we-fast-yet/traces/Permute.trace.log" --quiet --code "FileStream startUp: true. Harness new run: #(nil 'Permute' 250 1000)" /home/fniephaus/dev/are-we-fast-yet/benchmarks/Smalltalk/AWFY64-sista-fbc.image`
[engine] opt done Permute>>swap:with: |AST 74|Tier 2|Time 171( 152+19 )ms|Inlined 0Y 0N|IR 173/ 156|CodeSize 488|Addr 0x7ff123915a10|Src n/a
[engine] opt done Permute>>permute: |AST 138|Tier 2|Time 1028( 710+318 )ms|Inlined 20Y 8N|IR 2982/ 4177|CodeSize 20610|Addr 0x7ff123941910|Src n/a
[engine] opt done SequenceableCollection>>atAllPut: |AST 72|Tier 2|Time 115( 97+17 )ms|Inlined 0Y 0N|IR 184/ 407|CodeSize 1641|Addr 0x7ff123957410|Src n/a
[engine] opt done Permute>>verifyResult: |AST 15|Tier 2|Time 36( 33+2 )ms|Inlined 0Y 0N|IR 25/ 26|CodeSize 216|Addr 0x7ff12395b290|Src n/a
[engine] opt done ArrayedCollection class>>new:withAll: |AST 31|Tier 2|Time 131( 119+12 )ms|Inlined 1Y 0N|IR 237/ 289|CodeSize 977|Addr 0x7ff12395e390|Src n/a
[engine] opt done Permute>>benchmark |AST 49|Tier 2|Time 1020( 754+266 )ms|Inlined 23Y 8N|IR 3024/ 2967|CodeSize 11974|Addr 0x7ff123965010|Src n/a
[engine] opt done Benchmark>>innerBenchmarkLoop: |AST 59|Tier 2|Time 1085( 688+397 )ms|Inlined 25Y 8N|IR 3120/ 3754|CodeSize 15175|Addr 0x7ff123973910|Src n/a
[engine] opt done String class>>new: |AST 51|Tier 2|Time 169( 151+18 )ms|Inlined 2Y 1N|IR 213/ 472|CodeSize 1899|Addr 0x7ff123993a10|Src n/a
[engine] opt done SmallInteger>>printString |AST 152|Tier 2|Time 245( 221+23 )ms|Inlined 4Y 1N|IR 361/ 443|CodeSize 1368|Addr 0x7ff123997790|Src n/a
[engine] opt done SequenceableCollection>>copyReplaceFrom:to:with: |AST 177|Tier 2|Time 278( 238+40 )ms|Inlined 3Y 1N|IR 474/ 1035|CodeSize 4845|Addr 0x7ff1239a7890|Src n/a
[engine] Truffle runtime statistics for engine 2
Compilations : 11
Success : 10
Temporary Bailouts : 0
Permanent Bailouts : 0
Failed : 0
Interrupted : 1
Invalidated : 0
Queues : 11
Dequeues : 0
Splits : 191
Compilation Accuracy : 1.000000
Queue Accuracy : 1.000000
Compilation Utilization : 0.077869
Remaining Compilation Queue : 0
Time to queue : count= 11, sum= 175366, min= 36, average= 15942.40, max= 55079 (milliseconds), maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Time waiting in queue : count= 11, sum= 45, min= 1, average= 4.14, max= 16 (milliseconds), maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Time for compilation : count= 10, sum= 4303, min= 37, average= 430.35, max= 1086 (milliseconds), maxTarget=Benchmark>>innerBenchmarkLoop:
Truffle Tier : count= 10, sum= 3162, min= 33, average= 316.28, max= 754 (milliseconds), maxTarget=Permute>>benchmark
Graal Tier : count= 10, sum= 724, min= 1, average= 72.47, max= 262 (milliseconds), maxTarget=Benchmark>>innerBenchmarkLoop:
Code Installation : count= 10, sum= 415, min= 1, average= 41.60, max= 135 (milliseconds), maxTarget=Benchmark>>innerBenchmarkLoop:
Truffle node count : count= 10, sum= 12334, min= 23, average= 1233.40, max= 3662, maxTarget=Benchmark>>innerBenchmarkLoop:
Trivial : count= 10, sum= 4841, min= 8, average= 484.10, max= 1434, maxTarget=Benchmark>>innerBenchmarkLoop:
Non Trivial : count= 10, sum= 7493, min= 15, average= 749.30, max= 2228, maxTarget=Benchmark>>innerBenchmarkLoop:
Monomorphic : count= 10, sum= 7456, min= 15, average= 745.60, max= 2226, maxTarget=Benchmark>>innerBenchmarkLoop:
Polymorphic : count= 10, sum= 37, min= 0, average= 3.70, max= 11, maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Megamorphic : count= 10, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Permute>>swap:with:
Truffle call count : count= 10, sum= 105, min= 0, average= 10.50, max= 33, maxTarget=Benchmark>>innerBenchmarkLoop:
Indirect : count= 10, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Permute>>swap:with:
Direct : count= 10, sum= 105, min= 0, average= 10.50, max= 33, maxTarget=Benchmark>>innerBenchmarkLoop:
Dispatched : count= 10, sum= 27, min= 0, average= 2.70, max= 8, maxTarget=Permute>>permute:
Inlined : count= 10, sum= 78, min= 0, average= 7.80, max= 25, maxTarget=Benchmark>>innerBenchmarkLoop:
---------- :
Cloned : count= 10, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Permute>>swap:with:
Not Cloned : count= 10, sum= 105, min= 0, average= 10.50, max= 33, maxTarget=Benchmark>>innerBenchmarkLoop:
Truffle loops : count= 10, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Permute>>swap:with:
Graal node count :
After Truffle Tier : count= 10, sum= 10793, min= 25, average= 1079.30, max= 3120, maxTarget=Benchmark>>innerBenchmarkLoop:
After Graal Tier : count= 10, sum= 13726, min= 26, average= 1372.60, max= 4177, maxTarget=Permute>>permute:
Graal compilation result :
Code size : count= 10, sum= 59193, min= 216, average= 5919.30, max= 20610, maxTarget=Permute>>permute:
Total frame size : count= 10, sum= 1616, min= 32, average= 161.60, max= 544, maxTarget=Permute>>permute:
Exception handlers : count= 10, sum= 25, min= 0, average= 2.50, max= 9, maxTarget=Benchmark>>innerBenchmarkLoop:
Infopoints : count= 10, sum= 630, min= 4, average= 63.00, max= 215, maxTarget=Permute>>permute:
CALL : count= 10, sum= 455, min= 4, average= 45.50, max= 151, maxTarget=Permute>>permute:
IMPLICIT_EXCEPTION : count= 10, sum= 162, min= 0, average= 16.20, max= 57, maxTarget=Permute>>permute:
SAFEPOINT : count= 10, sum= 13, min= 0, average= 1.30, max= 7, maxTarget=Permute>>permute:
Marks : count= 10, sum= 110, min= 7, average= 11.00, max= 22, maxTarget=Permute>>permute:
Data references : count= 10, sum= 526, min= 3, average= 52.60, max= 148, maxTarget=Permute>>permute:
Raw
5d99b29f-Queens.trace.log
# Queens (iterations: 250, problem size: 1000) on Thu May 27 21:40:24 UTC 2021
# `/home/fniephaus/bin/graalvm-ee-java11-21.1.0/bin/trufflesqueak --experimental-options --smalltalk.disable-startup --smalltalk.disable-interrupts --engine.Mode=default --engine.MultiTier=false --engine.TraceCompilation --engine.CompilationStatistics --log.file="/home/fniephaus/dev/are-we-fast-yet/traces/Queens.trace.log" --quiet --code "FileStream startUp: true. Harness new run: #(nil 'Queens' 250 1000)" /home/fniephaus/dev/are-we-fast-yet/benchmarks/Smalltalk/AWFY64-sista-fbc.image`
[engine] opt done Queens>>row:column:put: |AST 83|Tier 2|Time 134( 108+27 )ms|Inlined 0Y 0N|IR 188/ 289|CodeSize 1130|Addr 0x7f097f8e8b10|Src n/a
[engine] opt done Queens>>row:column: |AST 77|Tier 2|Time 193( 167+26 )ms|Inlined 0Y 0N|IR 216/ 257|CodeSize 1117|Addr 0x7f097f8e8090|Src n/a
[engine] opt done SequenceableCollection>>atAllPut: |AST 72|Tier 2|Time 111( 79+33 )ms|Inlined 0Y 0N|IR 252/ 717|CodeSize 2826|Addr 0x7f097f900d10|Src n/a
[engine] opt done ArrayedCollection class>>new:withAll: |AST 31|Tier 2|Time 149( 110+39 )ms|Inlined 1Y 0N|IR 302/ 682|CodeSize 2303|Addr 0x7f097f91e090|Src n/a
[engine] opt done Queens>>placeQueen: |AST 149|Tier 2|Time 793( 536+256 )ms|Inlined 11Y 1N|IR 2084/ 2683|CodeSize 14517|Addr 0x7f097f920890|Src n/a
[engine] opt done True>>and: |AST 17|Tier 2|Time 40( 38+2 )ms|Inlined 0Y 0N|IR 23/ 28|CodeSize 213|Addr 0x7f097f92c610|Src n/a
[engine] opt done Queens>>verifyResult: |AST 9|Tier 2|Time 31( 29+2 )ms|Inlined 0Y 0N|IR 19/ 20|CodeSize 181|Addr 0x7f097f931f90|Src n/a
[engine] opt done Queens>>queens |AST 100|Tier 2|Time 1010( 574+436 )ms|Inlined 20Y 1N|IR 2848/ 3478|CodeSize 16209|Addr 0x7f097f93eb10|Src n/a
[engine] opt done Benchmark>>innerBenchmarkLoop: |AST 59|Tier 2|Time 622( 609+13 )ms|Inlined 1Y 1N|IR 138/ 441|CodeSize 1738|Addr 0x7f097f94a710|Src n/a
[engine] opt done Queens>>benchmark |AST 68|Tier 2|Time 1251( 675+576 )ms|Inlined 22Y 1N|IR 2949/ 4831|CodeSize 23569|Addr 0x7f097f94bc10|Src n/a
[engine] opt done String class>>new: |AST 51|Tier 2|Time 178( 160+18 )ms|Inlined 2Y 1N|IR 213/ 472|CodeSize 1899|Addr 0x7f097f96af10|Src n/a
[engine] opt done SmallInteger>>printString |AST 152|Tier 2|Time 246( 223+23 )ms|Inlined 4Y 1N|IR 361/ 443|CodeSize 1368|Addr 0x7f097f973390|Src n/a
[engine] Truffle runtime statistics for engine 2
Compilations : 14
Success : 12
Temporary Bailouts : 0
Permanent Bailouts : 0
Failed : 0
Interrupted : 2
Invalidated : 0
Queues : 14
Dequeues : 0
Splits : 191
Compilation Accuracy : 1.000000
Queue Accuracy : 1.000000
Compilation Utilization : 0.102359
Remaining Compilation Queue : 0
Time to queue : count= 14, sum= 149351, min= 44, average= 10667.93, max= 46768 (milliseconds), maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Time waiting in queue : count= 14, sum= 70, min= 1, average= 5.00, max= 17 (milliseconds), maxTarget=String class>>new:
Time for compilation : count= 12, sum= 4802, min= 32, average= 400.23, max= 1252 (milliseconds), maxTarget=Queens>>benchmark
Truffle Tier : count= 12, sum= 3308, min= 29, average= 275.67, max= 675 (milliseconds), maxTarget=Queens>>benchmark
Graal Tier : count= 12, sum= 1007, min= 1, average= 83.97, max= 396 (milliseconds), maxTarget=Queens>>benchmark
Code Installation : count= 12, sum= 487, min= 1, average= 40.59, max= 180 (milliseconds), maxTarget=Queens>>benchmark
Truffle node count : count= 13, sum= 9652, min= 13, average= 742.46, max= 2885, maxTarget=Queens>>benchmark
Trivial : count= 13, sum= 3741, min= 4, average= 287.77, max= 1112, maxTarget=Queens>>benchmark
Non Trivial : count= 13, sum= 5911, min= 9, average= 454.69, max= 1773, maxTarget=Queens>>benchmark
Monomorphic : count= 13, sum= 5862, min= 9, average= 450.92, max= 1765, maxTarget=Queens>>benchmark
Polymorphic : count= 13, sum= 49, min= 0, average= 3.77, max= 11, maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Megamorphic : count= 13, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Queens>>row:column:
Truffle call count : count= 13, sum= 71, min= 0, average= 5.46, max= 23, maxTarget=Queens>>benchmark
Indirect : count= 13, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Queens>>row:column:
Direct : count= 13, sum= 71, min= 0, average= 5.46, max= 23, maxTarget=Queens>>benchmark
Dispatched : count= 13, sum= 7, min= 0, average= 0.54, max= 1, maxTarget=Queens>>placeQueen:
Inlined : count= 13, sum= 64, min= 0, average= 4.92, max= 22, maxTarget=Queens>>benchmark
---------- :
Cloned : count= 13, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Queens>>row:column:
Not Cloned : count= 13, sum= 71, min= 0, average= 5.46, max= 23, maxTarget=Queens>>benchmark
Truffle loops : count= 13, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Queens>>row:column:
Graal node count :
After Truffle Tier : count= 13, sum= 10067, min= 19, average= 774.38, max= 2949, maxTarget=Queens>>benchmark
After Graal Tier : count= 13, sum= 15376, min= 20, average= 1182.77, max= 4831, maxTarget=Queens>>benchmark
Graal compilation result :
Code size : count= 12, sum= 67070, min= 181, average= 5589.17, max= 23569, maxTarget=Queens>>benchmark
Total frame size : count= 12, sum= 1920, min= 32, average= 160.00, max= 480, maxTarget=Queens>>placeQueen:
Exception handlers : count= 12, sum= 5, min= 0, average= 0.42, max= 2, maxTarget=Benchmark>>innerBenchmarkLoop:
Infopoints : count= 12, sum= 844, min= 4, average= 70.33, max= 264, maxTarget=Queens>>benchmark
CALL : count= 12, sum= 557, min= 4, average= 46.42, max= 173, maxTarget=Queens>>benchmark
IMPLICIT_EXCEPTION : count= 12, sum= 222, min= 0, average= 18.50, max= 73, maxTarget=Queens>>benchmark
SAFEPOINT : count= 12, sum= 65, min= 0, average= 5.42, max= 18, maxTarget=Queens>>placeQueen:
Marks : count= 12, sum= 158, min= 7, average= 13.17, max= 28, maxTarget=Queens>>queens
Data references : count= 12, sum= 766, min= 1, average= 63.83, max= 281, maxTarget=Queens>>benchmark
Raw
5d99b29f-Richards.trace.log
# Richards (iterations: 250, problem size: 100) on Thu May 27 21:29:28 UTC 2021
# `/home/fniephaus/bin/graalvm-ee-java11-21.1.0/bin/trufflesqueak --experimental-options --smalltalk.disable-startup --smalltalk.disable-interrupts --engine.Mode=default --engine.MultiTier=false --engine.TraceCompilation --engine.CompilationStatistics --log.file="/home/fniephaus/dev/are-we-fast-yet/traces/Richards.trace.log" --quiet --code "FileStream startUp: true. Harness new run: #(nil 'Richards' 250 100)" /home/fniephaus/dev/are-we-fast-yet/benchmarks/Smalltalk/AWFY64-sista-fbc.image`
[engine] opt done TaskState>>isTaskHoldingOrWaiting |AST 32|Tier 2|Time 136( 122+14 )ms|Inlined 0Y 0N|IR 125/ 98|CodeSize 353|Addr 0x7f0197900d10|Src n/a
[engine] opt done TaskState>>isWaitingWithPacket |AST 31|Tier 2|Time 99( 77+21 )ms|Inlined 0Y 0N|IR 84/ 101|CodeSize 362|Addr 0x7f0197900710|Src n/a
[engine] opt done Packet>>link: |AST 11|Tier 2|Time 43( 39+4 )ms|Inlined 0Y 0N|IR 61/ 181|CodeSize 476|Addr 0x7f0197909810|Src n/a
[engine] opt done Scheduler>>findTask: |AST 45|Tier 2|Time 113( 104+9 )ms|Inlined 0Y 0N|IR 70/ 131|CodeSize 564|Addr 0x7f019791ba10|Src n/a
[engine] opt done TaskControlBlock>>runTask |AST 121|Tier 2|Time 289( 233+56 )ms|Inlined 3Y 0N|IR 537/ 1469|CodeSize 4589|Addr 0x7f019791c910|Src n/a
[engine] opt done Packet>>identity: |AST 11|Tier 2|Time 37( 34+3 )ms|Inlined 0Y 0N|IR 74/ 88|CodeSize 273|Addr 0x7f0197928c90|Src n/a
[engine] opt done TaskState>>taskWaiting: |AST 11|Tier 2|Time 33( 31+3 )ms|Inlined 0Y 0N|IR 76/ 87|CodeSize 277|Addr 0x7f019792f290|Src n/a
[engine] opt done Scheduler>>createDevice:priority:work:state: |AST 157|Tier 2|Time 362( 318+44 )ms|Inlined 15Y 0N|IR 1140/ 1276|CodeSize 3687|Addr 0x7f0197951a10|Src n/a
[engine] opt done Scheduler>>wait |AST 27|Tier 2|Time 57( 53+4 )ms|Inlined 1Y 0N|IR 126/ 137|CodeSize 338|Addr 0x7f019795aa10|Src n/a
[engine] opt done Scheduler>>createWorker:priority:work:state: |AST 319|Tier 2|Time 511( 381+130 )ms|Inlined 19Y 0N|IR 1338/ 1564|CodeSize 4280|Addr 0x7f019795fb10|Src n/a
[engine] opt done TaskControlBlock>>addInput:checkPriority: |AST 97|Tier 2|Time 207( 183+24 )ms|Inlined 4Y 0N|IR 399/ 792|CodeSize 2286|Addr 0x7f0197965810|Src n/a
[engine] opt done Packet>>datum: |AST 11|Tier 2|Time 30( 27+3 )ms|Inlined 0Y 0N|IR 74/ 88|CodeSize 273|Addr 0x7f0197968510|Src n/a
[engine] opt deopt TaskControlBlock>>runTask |AST 121|Src n/a
[engine] opt inv. TaskControlBlock>>runTask |AST 121|Calls/Thres 7136/ 3|CallsAndLoop/Thres 7136/ 1000|Src n/a|Reason Profiled Return Type
[engine] opt done RBObject>>append:head: |AST 118|Tier 2|Time 94( 83+11 )ms|Inlined 2Y 0N|IR 216/ 412|CodeSize 1267|Addr 0x7f019796a990|Src n/a
[engine] opt done Scheduler>>queuePacket: |AST 127|Tier 2|Time 222( 185+37 )ms|Inlined 8Y 0N|IR 651/ 1020|CodeSize 2802|Addr 0x7f0197971e90|Src n/a
[engine] opt done Scheduler>>holdSelf |AST 49|Tier 2|Time 88( 83+5 )ms|Inlined 1Y 0N|IR 170/ 163|CodeSize 452|Addr 0x7f0197979090|Src n/a
[engine] opt done TaskState>>taskHolding: |AST 11|Tier 2|Time 29( 26+3 )ms|Inlined 0Y 0N|IR 76/ 87|CodeSize 277|Addr 0x7f0197979f90|Src n/a
[engine] opt done TaskControlBlock>>runTask |AST 121|Tier 2|Time 169( 137+31 )ms|Inlined 3Y 0N|IR 625/ 1487|CodeSize 4644|Addr 0x7f019797a610|Src n/a
[engine] opt done DeviceTaskDataRecord>>pending: |AST 11|Tier 2|Time 29( 26+3 )ms|Inlined 0Y 0N|IR 61/ 181|CodeSize 476|Addr 0x7f019797dc90|Src n/a
[engine] opt done TaskState>>packetPending: |AST 11|Tier 2|Time 31( 29+3 )ms|Inlined 0Y 0N|IR 74/ 85|CodeSize 267|Addr 0x7f019797e990|Src n/a
[engine] opt done Scheduler>>createHandler:priority:work:state: |AST 349|Tier 2|Time 780( 607+173 )ms|Inlined 34Y 0N|IR 2370/ 3825|CodeSize 12457|Addr 0x7f019797f710|Src n/a
[engine] opt done TaskState>>running |AST 16|Tier 2|Time 40( 34+6 )ms|Inlined 0Y 0N|IR 212/ 204|CodeSize 755|Addr 0x7f019798a710|Src n/a
[engine] opt done IdleTaskDataRecord>>count: |AST 11|Tier 2|Time 33( 30+3 )ms|Inlined 0Y 0N|IR 73/ 88|CodeSize 273|Addr 0x7f019798c110|Src n/a
[engine] opt done IdleTaskDataRecord>>control: |AST 11|Tier 2|Time 32( 30+3 )ms|Inlined 0Y 0N|IR 73/ 88|CodeSize 273|Addr 0x7f019798c790|Src n/a
[engine] opt done WorkerTaskDataRecord>>count: |AST 11|Tier 2|Time 31( 28+3 )ms|Inlined 0Y 0N|IR 73/ 88|CodeSize 273|Addr 0x7f019798ce10|Src n/a
[engine] opt done RBObject class>>DeviceA |AST 8|Tier 2|Time 22( 20+2 )ms|Inlined 0Y 0N|IR 18/ 18|CodeSize 179|Addr 0x7f019798f010|Src n/a
[engine] opt done RBObject class>>DeviceB |AST 8|Tier 2|Time 22( 20+2 )ms|Inlined 0Y 0N|IR 18/ 18|CodeSize 179|Addr 0x7f019798fa10|Src n/a
[engine] opt done Scheduler>>release: |AST 93|Tier 2|Time 113( 106+7 )ms|Inlined 2Y 0N|IR 191/ 253|CodeSize 761|Addr 0x7f019798fe10|Src n/a
[engine] opt done RBObject class>>HandlerA |AST 8|Tier 2|Time 23( 21+2 )ms|Inlined 0Y 0N|IR 18/ 18|CodeSize 179|Addr 0x7f0197990d90|Src n/a
[engine] opt done TaskState>>packetPending |AST 18|Tier 2|Time 111( 108+3 )ms|Inlined 0Y 0N|IR 128/ 123|CodeSize 358|Addr 0x7f0197998790|Src n/a
[engine] opt done Scheduler>>createIdler:priority:work:state: |AST 236|Tier 2|Time 358( 331+28 )ms|Inlined 13Y 0N|IR 818/ 782|CodeSize 1751|Addr 0x7f019799b310|Src n/a
[engine] opt done Scheduler>>schedule |AST 108|Tier 2|Time 328( 226+102 )ms|Inlined 5Y 0N|IR 987/ 2675|CodeSize 9814|Addr 0x7f019799dc90|Src n/a
[engine] opt done SequenceableCollection>>atAllPut: |AST 72|Tier 2|Time 88( 68+19 )ms|Inlined 0Y 0N|IR 206/ 479|CodeSize 2192|Addr 0x7f01979a4e90|Src n/a
[engine] opt inv. SequenceableCollection>>atAllPut: |AST 72|Calls/Thres 379/ 3|CallsAndLoop/Thres 2051/ 1000|Src n/a
[engine] opt done SequenceableCollection>>atAllPut: |AST 72|Tier 2|Time 88( 67+22 )ms|Inlined 0Y 0N|IR 206/ 510|CodeSize 2184|Addr 0x7f01979a6a90|Src n/a
[engine] opt done ArrayedCollection class>>new:withAll: |AST 31|Tier 2|Time 145( 113+32 )ms|Inlined 1Y 0N|IR 258/ 672|CodeSize 2513|Addr 0x7f01979b0110|Src n/a
[engine] opt done Behavior>>new <split-74fef3f7> |AST 26|Tier 2|Time 56( 53+3 )ms|Inlined 0Y 0N|IR 33/ 97|CodeSize 433|Addr 0x7f01979b3a10|Src n/a
[engine] opt done Packet class>>create:identity:kind: |AST 35|Tier 2|Time 169( 156+13 )ms|Inlined 4Y 0N|IR 310/ 429|CodeSize 1449|Addr 0x7f01979b4810|Src n/a
[engine] opt done Scheduler>>createPacket:identity:kind: |AST 29|Tier 2|Time 176( 162+13 )ms|Inlined 5Y 0N|IR 351/ 431|CodeSize 1462|Addr 0x7f01979b5690|Src n/a
[engine] opt done Behavior>>new <split-5bb8f9e2> |AST 26|Tier 2|Time 55( 49+6 )ms|Inlined 0Y 0N|IR 94/ 374|CodeSize 1320|Addr 0x7f01979ba390|Src n/a
[engine] opt done TaskControlBlock class>>link:create:priority:initialWorkQueue:initialState:function:privateData:|AST 47|Tier 2|Time 136( 122+14 )ms|Inlined 5Y 0N|IR 425/ 707|CodeSize 2202|Addr 0x7f01979bb090|Src n/a
[engine] opt done Scheduler>>createTask:priority:work:state:function:data: |AST 69|Tier 2|Time 191( 158+33 )ms|Inlined 6Y 0N|IR 578/ 1393|CodeSize 4930|Addr 0x7f01979bcb10|Src n/a
[engine] opt done RBObject class>>HandlerB |AST 8|Tier 2|Time 20( 18+2 )ms|Inlined 0Y 0N|IR 18/ 18|CodeSize 179|Addr 0x7f01979c0210|Src n/a
[engine] opt done TaskState>>waitingWithPacket |AST 17|Tier 2|Time 42( 38+4 )ms|Inlined 0Y 0N|IR 133/ 152|CodeSize 421|Addr 0x7f01979c2910|Src n/a
[engine] opt done Behavior>>new <split-516ebdf8> |AST 26|Tier 2|Time 53( 51+3 )ms|Inlined 0Y 0N|IR 33/ 97|CodeSize 433|Addr 0x7f01979c3210|Src n/a
[engine] opt done TaskState class>>waitingWithPacket |AST 26|Tier 2|Time 81( 74+6 )ms|Inlined 2Y 0N|IR 166/ 248|CodeSize 579|Addr 0x7f01979c4710|Src n/a
[engine] opt done HandlerTaskDataRecord class>>create |AST 26|Tier 2|Time 117( 114+3 )ms|Inlined 2Y 0N|IR 42/ 115|CodeSize 479|Addr 0x7f01979c5b90|Src n/a
[engine] opt done Scheduler>>initialize |AST 77|Tier 2|Time 186( 177+10 )ms|Inlined 2Y 0N|IR 341/ 488|CodeSize 1298|Addr 0x7f01979c9190|Src n/a
[engine] opt done TaskState class>>waiting |AST 26|Tier 2|Time 79( 73+6 )ms|Inlined 2Y 0N|IR 166/ 248|CodeSize 579|Addr 0x7f01979ca010|Src n/a
[engine] opt done DeviceTaskDataRecord class>>create |AST 26|Tier 2|Time 81( 78+3 )ms|Inlined 2Y 0N|IR 42/ 115|CodeSize 479|Addr 0x7f01979cad10|Src n/a
[engine] opt done Scheduler>>createHandler:priority:work:state: |AST 55|Tier 2|Time 342( 271+71 )ms|Inlined 10Y 0N|IR 816/ 2987|CodeSize 12110|Addr 0x7f01979cb390|Src n/a
[engine] opt done Scheduler>>createDevice:priority:work:state: |AST 55|Tier 2|Time 278( 208+70 )ms|Inlined 10Y 0N|IR 816/ 2987|CodeSize 12110|Addr 0x7f01979d0d10|Src n/a
[engine] opt done Behavior>>new <split-25c5e994> |AST 28|Tier 2|Time 161( 153+8 )ms|Inlined 3Y 0N|IR 226/ 412|CodeSize 1411|Addr 0x7f01979d7110|Src n/a
[engine] opt done Scheduler class>>new |AST 26|Tier 2|Time 226( 215+10 )ms|Inlined 7Y 0N|IR 380/ 412|CodeSize 1411|Addr 0x7f01979d7f90|Src n/a
[engine] opt done Richards>>benchmark |AST 30|Tier 2|Time 238( 223+15 )ms|Inlined 8Y 1N|IR 447/ 684|CodeSize 2295|Addr 0x7f01979d9810|Src n/a
[engine] opt done TaskState class>>running |AST 26|Tier 2|Time 82( 73+10 )ms|Inlined 2Y 0N|IR 217/ 288|CodeSize 798|Addr 0x7f01979daa90|Src n/a
[engine] opt done Benchmark>>innerBenchmarkLoop: |AST 59|Tier 2|Time 266( 233+34 )ms|Inlined 10Y 1N|IR 547/ 1412|CodeSize 5041|Addr 0x7f01979dc390|Src n/a
[engine] opt done IdleTaskDataRecord class>>create |AST 26|Tier 2|Time 70( 67+3 )ms|Inlined 2Y 0N|IR 35/ 99|CodeSize 445|Addr 0x7f01979dea10|Src n/a
[engine] opt done Richards>>verifyResult: |AST 9|Tier 2|Time 21( 20+1 )ms|Inlined 0Y 0N|IR 19/ 20|CodeSize 181|Addr 0x7f01979df090|Src n/a
[engine] opt done Scheduler>>createIdler:priority:work:state: |AST 55|Tier 2|Time 331( 202+129 )ms|Inlined 10Y 0N|IR 808/ 2972|CodeSize 12342|Addr 0x7f01979df490|Src n/a
[engine] opt done WorkerTaskDataRecord class>>create |AST 26|Tier 2|Time 103( 77+27 )ms|Inlined 3Y 0N|IR 43/ 116|CodeSize 485|Addr 0x7f01979e4a90|Src n/a
[engine] opt done True>>and: |AST 17|Tier 2|Time 32( 30+2 )ms|Inlined 0Y 0N|IR 23/ 28|CodeSize 213|Addr 0x7f01979e5810|Src n/a
[engine] opt done Scheduler>>createWorker:priority:work:state: |AST 55|Tier 2|Time 375( 305+70 )ms|Inlined 11Y 0N|IR 817/ 2989|CodeSize 12248|Addr 0x7f01979e5f10|Src n/a
[engine] opt done Scheduler>>start |AST 698|Tier 2|Time 2050(1558+492 )ms|Inlined 93Y 7N|IR 4850/10475|CodeSize 42212|Addr 0x7f01979ec210|Src n/a
[engine] opt done String class>>new: |AST 51|Tier 2|Time 167( 148+19 )ms|Inlined 2Y 1N|IR 213/ 472|CodeSize 1899|Addr 0x7f0197a0a710|Src n/a
[engine] opt done SmallInteger>>printString |AST 152|Tier 2|Time 282( 253+29 )ms|Inlined 4Y 1N|IR 361/ 443|CodeSize 1368|Addr 0x7f0197a0c590|Src n/a
[engine] opt done SequenceableCollection>>copyReplaceFrom:to:with: |AST 177|Tier 2|Time 272( 233+38 )ms|Inlined 3Y 1N|IR 474/ 1035|CodeSize 4845|Addr 0x7f0197a13b10|Src n/a
[engine] Truffle runtime statistics for engine 2
Compilations : 69
Success : 65
Temporary Bailouts : 0
Permanent Bailouts : 0
Failed : 0
Interrupted : 4
Invalidated : 2
Profiled Return Type : 1
Queues : 87
Dequeues : 22
Target inlined into only caller : 21
null : 1
Splits : 201
Compilation Accuracy : 0.971014
Queue Accuracy : 0.747126
Compilation Utilization : 0.052755
Remaining Compilation Queue : 0
Time to queue : count= 87, sum= 1028740, min= 98, average= 11824.61, max= 219965 (milliseconds), maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Time waiting in queue : count= 69, sum= 18728, min= 0, average= 271.42, max= 934 (milliseconds), maxTarget=WorkerTaskDataRecord>>count:
Time for compilation : count= 65, sum= 11644, min= 20, average= 179.14, max= 2050 (milliseconds), maxTarget=Scheduler>>start
Truffle Tier : count= 65, sum= 9570, min= 18, average= 147.24, max= 1557 (milliseconds), maxTarget=Scheduler>>start
Graal Tier : count= 65, sum= 1360, min= 1, average= 20.93, max= 330 (milliseconds), maxTarget=Scheduler>>start
Code Installation : count= 65, sum= 713, min= 1, average= 10.98, max= 162 (milliseconds), maxTarget=Scheduler>>start
Truffle node count : count= 65, sum= 25858, min= 12, average= 397.82, max= 6055, maxTarget=Scheduler>>start
Trivial : count= 65, sum= 9969, min= 4, average= 153.37, max= 2255, maxTarget=Scheduler>>start
Non Trivial : count= 65, sum= 15889, min= 8, average= 244.45, max= 3800, maxTarget=Scheduler>>start
Monomorphic : count= 65, sum= 15778, min= 8, average= 242.74, max= 3777, maxTarget=Scheduler>>start
Polymorphic : count= 65, sum= 111, min= 0, average= 1.71, max= 23, maxTarget=Scheduler>>start
Megamorphic : count= 65, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=TaskState>>isWaitingWithPacket
Truffle call count : count= 65, sum= 334, min= 0, average= 5.14, max= 100, maxTarget=Scheduler>>start
Indirect : count= 65, sum= 3, min= 0, average= 0.05, max= 1, maxTarget=TaskControlBlock>>runTask
Direct : count= 65, sum= 331, min= 0, average= 5.09, max= 100, maxTarget=Scheduler>>start
Dispatched : count= 65, sum= 12, min= 0, average= 0.18, max= 7, maxTarget=Scheduler>>start
Inlined : count= 65, sum= 319, min= 0, average= 4.91, max= 93, maxTarget=Scheduler>>start
---------- :
Cloned : count= 65, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=TaskState>>isWaitingWithPacket
Not Cloned : count= 65, sum= 331, min= 0, average= 5.09, max= 100, maxTarget=Scheduler>>start
Truffle loops : count= 65, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=TaskState>>isWaitingWithPacket
Graal node count :
After Truffle Tier : count= 65, sum= 25450, min= 18, average= 391.54, max= 4850, maxTarget=Scheduler>>start
After Graal Tier : count= 65, sum= 52031, min= 18, average= 800.48, max= 10475, maxTarget=Scheduler>>start
Graal compilation result :
Code size : count= 65, sum= 189741, min= 179, average= 2919.09, max= 42212, maxTarget=Scheduler>>start
Total frame size : count= 65, sum= 5136, min= 32, average= 79.02, max= 432, maxTarget=Scheduler>>start
Exception handlers : count= 65, sum= 16, min= 0, average= 0.25, max= 7, maxTarget=Scheduler>>start
Infopoints : count= 65, sum= 1879, min= 4, average= 28.91, max= 335, maxTarget=Scheduler>>start
CALL : count= 65, sum= 1526, min= 4, average= 23.48, max= 269, maxTarget=Scheduler>>start
IMPLICIT_EXCEPTION : count= 65, sum= 328, min= 0, average= 5.05, max= 66, maxTarget=Scheduler>>start
SAFEPOINT : count= 65, sum= 25, min= 0, average= 0.38, max= 4, maxTarget=Scheduler>>createHandler:priority:work:state:
Marks : count= 65, sum= 516, min= 7, average= 7.94, max= 14, maxTarget=Scheduler>>start
Data references : count= 65, sum= 1966, min= 1, average= 30.25, max= 499, maxTarget=Scheduler>>start
Raw
5d99b29f-Sieve.trace.log
# Sieve (iterations: 250, problem size: 3000) on Thu May 27 21:28:28 UTC 2021
# `/home/fniephaus/bin/graalvm-ee-java11-21.1.0/bin/trufflesqueak --experimental-options --smalltalk.disable-startup --smalltalk.disable-interrupts --engine.Mode=default --engine.MultiTier=false --engine.TraceCompilation --engine.CompilationStatistics --log.file="/home/fniephaus/dev/are-we-fast-yet/traces/Sieve.trace.log" --quiet --code "FileStream startUp: true. Harness new run: #(nil 'Sieve' 250 3000)" /home/fniephaus/dev/are-we-fast-yet/benchmarks/Smalltalk/AWFY64-sista-fbc.image`
[engine] opt done Sieve>>sieve:size: |AST 134|Tier 2|Time 197( 166+31 )ms|Inlined 0Y 0N|IR 223/ 367|CodeSize 1635|Addr 0x7f7cc3917290|Src n/a
[engine] opt done Magnitude>>min: |AST 21|Tier 2|Time 37( 35+3 )ms|Inlined 0Y 0N|IR 29/ 34|CodeSize 206|Addr 0x7f7cc391ff90|Src n/a
[engine] opt done SequenceableCollection>>from:to:put: |AST 162|Tier 2|Time 164( 144+20 )ms|Inlined 1Y 0N|IR 228/ 656|CodeSize 2871|Addr 0x7f7cc3934610|Src n/a
[engine] opt done SequenceableCollection>>atAllPut: |AST 48|Tier 2|Time 177( 157+20 )ms|Inlined 2Y 0N|IR 265/ 550|CodeSize 1947|Addr 0x7f7cc3947f10|Src n/a
[engine] opt done ArrayedCollection class>>new:withAll: |AST 31|Tier 2|Time 234( 205+29 )ms|Inlined 3Y 0N|IR 335/ 625|CodeSize 2453|Addr 0x7f7cc3949a10|Src n/a
[engine] opt done Sieve>>verifyResult: |AST 15|Tier 2|Time 35( 32+2 )ms|Inlined 0Y 0N|IR 25/ 26|CodeSize 216|Addr 0x7f7cc394bc10|Src n/a
[engine] opt done Sieve>>benchmark |AST 44|Tier 2|Time 301( 255+47 )ms|Inlined 5Y 0N|IR 564/ 922|CodeSize 3231|Addr 0x7f7cc394df10|Src n/a
[engine] opt done Benchmark>>innerBenchmarkLoop: |AST 59|Tier 2|Time 301( 237+63 )ms|Inlined 7Y 0N|IR 657/ 997|CodeSize 3158|Addr 0x7f7cc3958590|Src n/a
[engine] opt done String class>>new: |AST 51|Tier 2|Time 175( 156+19 )ms|Inlined 2Y 1N|IR 213/ 472|CodeSize 1899|Addr 0x7f7cc396c510|Src n/a
[engine] opt done SmallInteger>>printString |AST 152|Tier 2|Time 243( 221+22 )ms|Inlined 4Y 1N|IR 310/ 601|CodeSize 2107|Addr 0x7f7cc3973890|Src n/a
[engine] opt done SequenceableCollection>>copyReplaceFrom:to:with: |AST 177|Tier 2|Time 275( 235+41 )ms|Inlined 3Y 1N|IR 474/ 1035|CodeSize 4845|Addr 0x7f7cc397aa10|Src n/a
[engine] Truffle runtime statistics for engine 2
Compilations : 12
Success : 11
Temporary Bailouts : 0
Permanent Bailouts : 0
Failed : 0
Interrupted : 1
Invalidated : 0
Queues : 12
Dequeues : 0
Splits : 191
Compilation Accuracy : 1.000000
Queue Accuracy : 1.000000
Compilation Utilization : 0.040332
Remaining Compilation Queue : 0
Time to queue : count= 12, sum= 169220, min= 119, average= 14101.69, max= 53846 (milliseconds), maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Time waiting in queue : count= 12, sum= 274, min= 1, average= 22.89, max= 203 (milliseconds), maxTarget=Sieve>>verifyResult:
Time for compilation : count= 11, sum= 2176, min= 36, average= 197.82, max= 301 (milliseconds), maxTarget=Benchmark>>innerBenchmarkLoop:
Truffle Tier : count= 11, sum= 1840, min= 32, average= 167.33, max= 253 (milliseconds), maxTarget=Sieve>>benchmark
Graal Tier : count= 11, sum= 222, min= 1, average= 20.27, max= 44 (milliseconds), maxTarget=Benchmark>>innerBenchmarkLoop:
Code Installation : count= 11, sum= 112, min= 1, average= 10.22, max= 27 (milliseconds), maxTarget=Sieve>>sieve:size:
Truffle node count : count= 11, sum= 4228, min= 23, average= 384.36, max= 812, maxTarget=Benchmark>>innerBenchmarkLoop:
Trivial : count= 11, sum= 1596, min= 8, average= 145.09, max= 298, maxTarget=Benchmark>>innerBenchmarkLoop:
Non Trivial : count= 11, sum= 2632, min= 15, average= 239.27, max= 514, maxTarget=Benchmark>>innerBenchmarkLoop:
Monomorphic : count= 11, sum= 2603, min= 15, average= 236.64, max= 514, maxTarget=Benchmark>>innerBenchmarkLoop:
Polymorphic : count= 11, sum= 29, min= 0, average= 2.64, max= 11, maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Megamorphic : count= 11, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Sieve>>sieve:size:
Truffle call count : count= 11, sum= 30, min= 0, average= 2.73, max= 7, maxTarget=Benchmark>>innerBenchmarkLoop:
Indirect : count= 11, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Sieve>>sieve:size:
Direct : count= 11, sum= 30, min= 0, average= 2.73, max= 7, maxTarget=Benchmark>>innerBenchmarkLoop:
Dispatched : count= 11, sum= 3, min= 0, average= 0.27, max= 1, maxTarget=String class>>new:
Inlined : count= 11, sum= 27, min= 0, average= 2.45, max= 7, maxTarget=Benchmark>>innerBenchmarkLoop:
---------- :
Cloned : count= 11, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Sieve>>sieve:size:
Not Cloned : count= 11, sum= 30, min= 0, average= 2.73, max= 7, maxTarget=Benchmark>>innerBenchmarkLoop:
Truffle loops : count= 11, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Sieve>>sieve:size:
Graal node count :
After Truffle Tier : count= 11, sum= 3323, min= 25, average= 302.09, max= 657, maxTarget=Benchmark>>innerBenchmarkLoop:
After Graal Tier : count= 11, sum= 6285, min= 26, average= 571.36, max= 1035, maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Graal compilation result :
Code size : count= 11, sum= 24568, min= 206, average= 2233.45, max= 4845, maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Total frame size : count= 11, sum= 1152, min= 32, average= 104.73, max= 208, maxTarget=Benchmark>>innerBenchmarkLoop:
Exception handlers : count= 11, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=Sieve>>sieve:size:
Infopoints : count= 11, sum= 226, min= 4, average= 20.55, max= 45, maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
CALL : count= 11, sum= 173, min= 4, average= 15.73, max= 32, maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
IMPLICIT_EXCEPTION : count= 11, sum= 36, min= 0, average= 3.27, max= 13, maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
SAFEPOINT : count= 11, sum= 17, min= 0, average= 1.55, max= 5, maxTarget=Sieve>>benchmark
Marks : count= 11, sum= 98, min= 7, average= 8.91, max= 12, maxTarget=Sieve>>benchmark
Data references : count= 11, sum= 170, min= 1, average= 15.45, max= 44, maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Raw
5d99b29f-Storage.trace.log
# Storage (iterations: 250, problem size: 1000) on Thu May 27 21:24:54 UTC 2021
# `/home/fniephaus/bin/graalvm-ee-java11-21.1.0/bin/trufflesqueak --experimental-options --smalltalk.disable-startup --smalltalk.disable-interrupts --engine.Mode=default --engine.MultiTier=false --engine.TraceCompilation --engine.CompilationStatistics --log.file="/home/fniephaus/dev/are-we-fast-yet/traces/Storage.trace.log" --quiet --code "FileStream startUp: true. Harness new run: #(nil 'Storage' 250 1000)" /home/fniephaus/dev/are-we-fast-yet/benchmarks/Smalltalk/AWFY64-sista-fbc.image`
[engine] opt done SomRandom>>next |AST 39|Tier 2|Time 122( 101+21 )ms|Inlined 0Y 0N|IR 83/ 158|CodeSize 527|Addr 0x7eff7f8dfc90|Src n/a
[engine] opt done Storage>>buildTreeDepth:with: |AST 154|Tier 2|Time 1988( 376+1613)ms|Inlined 5Y 1N|IR 1059/17106|CodeSize 78762|Addr 0x7eff7f919910|Src n/a
[engine] opt done SomRandom>>initialize |AST 10|Tier 2|Time 30( 26+4 )ms|Inlined 0Y 0N|IR 68/ 77|CodeSize 255|Addr 0x7eff7f95af10|Src n/a
[engine] opt done Behavior>>new <split-2234078> |AST 28|Tier 2|Time 73( 70+3 )ms|Inlined 1Y 0N|IR 34/ 98|CodeSize 439|Addr 0x7eff7f960410|Src n/a
[engine] opt done SomRandom class>>new |AST 26|Tier 2|Time 84( 80+4 )ms|Inlined 3Y 0N|IR 34/ 98|CodeSize 439|Addr 0x7eff7f961010|Src n/a
[engine] opt done Storage>>verifyResult: |AST 15|Tier 2|Time 29( 27+2 )ms|Inlined 0Y 0N|IR 25/ 26|CodeSize 216|Addr 0x7eff7f961d90|Src n/a
[engine] opt done Storage>>benchmark |AST 49|Tier 2|Time 1742( 290+1452)ms|Inlined 10Y 1N|IR 801/11342|CodeSize 37541|Addr 0x7eff7f967110|Src n/a
[engine] opt done Benchmark>>innerBenchmarkLoop: |AST 59|Tier 2|Time 2177( 423+1754)ms|Inlined 12Y 1N|IR 898/14361|CodeSize 49755|Addr 0x7eff7f99a590|Src n/a
[engine] opt done String class>>new: |AST 51|Tier 2|Time 181( 162+19 )ms|Inlined 2Y 1N|IR 213/ 472|CodeSize 1899|Addr 0x7eff7f9d5410|Src n/a
[engine] opt done SmallInteger>>printString |AST 152|Tier 2|Time 259( 235+24 )ms|Inlined 4Y 1N|IR 361/ 443|CodeSize 1368|Addr 0x7eff7f9db590|Src n/a
[engine] opt done SequenceableCollection>>copyReplaceFrom:to:with: |AST 177|Tier 2|Time 282( 244+39 )ms|Inlined 3Y 1N|IR 474/ 1035|CodeSize 4845|Addr 0x7eff7f9eb210|Src n/a
[engine] Truffle runtime statistics for engine 2
Compilations : 12
Success : 10
Temporary Bailouts : 0
Permanent Bailouts : 0
Failed : 0
Interrupted : 2
Invalidated : 0
Queues : 12
Dequeues : 0
Splits : 192
Compilation Accuracy : 1.000000
Queue Accuracy : 1.000000
Compilation Utilization : 0.134399
Remaining Compilation Queue : 0
Time to queue : count= 12, sum= 166243, min= 35, average= 13853.66, max= 49766 (milliseconds), maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Time waiting in queue : count= 12, sum= 130, min= 1, average= 10.92, max= 76 (milliseconds), maxTarget=Storage>>verifyResult:
Time for compilation : count= 10, sum= 6711, min= 30, average= 671.12, max= 2177 (milliseconds), maxTarget=Benchmark>>innerBenchmarkLoop:
Truffle Tier : count= 10, sum= 1788, min= 26, average= 178.82, max= 423 (milliseconds), maxTarget=Benchmark>>innerBenchmarkLoop:
Graal Tier : count= 10, sum= 3062, min= 1, average= 306.22, max= 1124 (milliseconds), maxTarget=Benchmark>>innerBenchmarkLoop:
Code Installation : count= 10, sum= 1860, min= 1, average= 186.08, max= 644 (milliseconds), maxTarget=Storage>>buildTreeDepth:with:
Truffle node count : count= 11, sum= 5029, min= 18, average= 457.18, max= 1260, maxTarget=Benchmark>>innerBenchmarkLoop:
Trivial : count= 11, sum= 1951, min= 8, average= 177.36, max= 484, maxTarget=Benchmark>>innerBenchmarkLoop:
Non Trivial : count= 11, sum= 3078, min= 10, average= 279.82, max= 776, maxTarget=Benchmark>>innerBenchmarkLoop:
Monomorphic : count= 11, sum= 3031, min= 10, average= 275.55, max= 770, maxTarget=Benchmark>>innerBenchmarkLoop:
Polymorphic : count= 11, sum= 47, min= 0, average= 4.27, max= 11, maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Megamorphic : count= 11, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=SomRandom>>next
Truffle call count : count= 11, sum= 46, min= 0, average= 4.18, max= 13, maxTarget=Benchmark>>innerBenchmarkLoop:
Indirect : count= 11, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=SomRandom>>next
Direct : count= 11, sum= 46, min= 0, average= 4.18, max= 13, maxTarget=Benchmark>>innerBenchmarkLoop:
Dispatched : count= 11, sum= 6, min= 0, average= 0.55, max= 1, maxTarget=Storage>>buildTreeDepth:with:
Inlined : count= 11, sum= 40, min= 0, average= 3.64, max= 12, maxTarget=Benchmark>>innerBenchmarkLoop:
---------- :
Cloned : count= 11, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=SomRandom>>next
Not Cloned : count= 11, sum= 46, min= 0, average= 4.18, max= 13, maxTarget=Benchmark>>innerBenchmarkLoop:
Truffle loops : count= 11, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=SomRandom>>next
Graal node count :
After Truffle Tier : count= 11, sum= 4050, min= 25, average= 368.18, max= 1059, maxTarget=Storage>>buildTreeDepth:with:
After Graal Tier : count= 11, sum= 45216, min= 26, average= 4110.55, max= 17106, maxTarget=Storage>>buildTreeDepth:with:
Graal compilation result :
Code size : count= 11, sum= 176046, min= 216, average= 16004.18, max= 78762, maxTarget=Storage>>buildTreeDepth:with:
Total frame size : count= 11, sum= 4656, min= 32, average= 423.27, max= 1696, maxTarget=Storage>>buildTreeDepth:with:
Exception handlers : count= 11, sum= 176, min= 0, average= 16.00, max= 64, maxTarget=Storage>>benchmark
Infopoints : count= 11, sum= 1908, min= 4, average= 173.45, max= 794, maxTarget=Storage>>buildTreeDepth:with:
CALL : count= 11, sum= 1513, min= 4, average= 137.55, max= 611, maxTarget=Storage>>buildTreeDepth:with:
IMPLICIT_EXCEPTION : count= 11, sum= 389, min= 0, average= 35.36, max= 180, maxTarget=Storage>>buildTreeDepth:with:
SAFEPOINT : count= 11, sum= 6, min= 0, average= 0.55, max= 3, maxTarget=Storage>>buildTreeDepth:with:
Marks : count= 11, sum= 263, min= 7, average= 23.91, max= 71, maxTarget=Storage>>benchmark
Data references : count= 11, sum= 1980, min= 2, average= 180.00, max= 724, maxTarget=Storage>>buildTreeDepth:with:
Raw
5d99b29f-Towers.trace.log
# Towers (iterations: 250, problem size: 600) on Thu May 27 21:25:50 UTC 2021
# `/home/fniephaus/bin/graalvm-ee-java11-21.1.0/bin/trufflesqueak --experimental-options --smalltalk.disable-startup --smalltalk.disable-interrupts --engine.Mode=default --engine.MultiTier=false --engine.TraceCompilation --engine.CompilationStatistics --log.file="/home/fniephaus/dev/are-we-fast-yet/traces/Towers.trace.log" --quiet --code "FileStream startUp: true. Harness new run: #(nil 'Towers' 250 600)" /home/fniephaus/dev/are-we-fast-yet/benchmarks/Smalltalk/AWFY64-sista-fbc.image`
[engine] opt done TowersDisk>>next: |AST 11|Tier 2|Time 113( 97+15 )ms|Inlined 0Y 0N|IR 61/ 182|CodeSize 476|Addr 0x7fc69f6d3390|Src n/a
[engine] opt done Towers>>pushDisk:onPile: |AST 99|Tier 2|Time 224( 189+35 )ms|Inlined 1Y 0N|IR 356/ 1147|CodeSize 4001|Addr 0x7fc69f6ed210|Src n/a
[engine] opt done Towers>>moveTopDiskFrom:to: |AST 49|Tier 2|Time 224( 166+59 )ms|Inlined 4Y 0N|IR 615/ 1665|CodeSize 5504|Addr 0x7fc69f700290|Src n/a
[engine] opt done TowersDisk class>>new: |AST 29|Tier 2|Time 90( 86+4 )ms|Inlined 2Y 0N|IR 37/ 102|CodeSize 441|Addr 0x7fc69f727f90|Src n/a
[engine] opt done Towers>>buildTowerAt:disks: |AST 67|Tier 2|Time 266( 187+79 )ms|Inlined 5Y 0N|IR 461/ 1797|CodeSize 8232|Addr 0x7fc69f729990|Src n/a
[engine] opt done Towers>>move:disksFrom:to: |AST 128|Tier 2|Time 2099(1423+676 )ms|Inlined 43Y 5N|IR 4747/12028|CodeSize 44208|Addr 0x7fc69f72ee90|Src n/a
[engine] opt done Towers>>verifyResult: |AST 15|Tier 2|Time 32( 30+2 )ms|Inlined 0Y 0N|IR 25/ 26|CodeSize 216|Addr 0x7fc69f754590|Src n/a
[engine] opt done Towers>>benchmark |AST 65|Tier 2|Time 2155(1445+710 )ms|Inlined 50Y 5N|IR 2940/ 7019|CodeSize 21573|Addr 0x7fc69f762310|Src n/a
[engine] opt done Benchmark>>innerBenchmarkLoop: |AST 59|Tier 2|Time 3423(1673+1750)ms|Inlined 85Y 8N|IR 4760/17117|CodeSize 54825|Addr 0x7fc69f77e990|Src n/a
[engine] opt done String class>>new: |AST 51|Tier 2|Time 169( 151+17 )ms|Inlined 2Y 1N|IR 213/ 472|CodeSize 1899|Addr 0x7fc69f7c9690|Src n/a
[engine] opt done SmallInteger>>printString |AST 152|Tier 2|Time 253( 229+24 )ms|Inlined 4Y 1N|IR 361/ 443|CodeSize 1368|Addr 0x7fc69f7cbf90|Src n/a
[engine] opt done SequenceableCollection>>copyReplaceFrom:to:with: |AST 177|Tier 2|Time 279( 242+38 )ms|Inlined 3Y 1N|IR 474/ 1035|CodeSize 4845|Addr 0x7fc69f7d6890|Src n/a
[engine] Truffle runtime statistics for engine 2
Compilations : 14
Success : 12
Temporary Bailouts : 0
Permanent Bailouts : 0
Failed : 0
Interrupted : 2
Invalidated : 0
Queues : 16
Dequeues : 3
Target inlined into only caller : 3
Splits : 192
Compilation Accuracy : 1.000000
Queue Accuracy : 0.812500
Compilation Utilization : 0.126026
Remaining Compilation Queue : 0
Time to queue : count= 16, sum= 240553, min= 51, average= 15034.57, max= 74034 (milliseconds), maxTarget=SequenceableCollection>>copyReplaceFrom:to:with:
Time waiting in queue : count= 14, sum= 463, min= 1, average= 33.14, max= 238 (milliseconds), maxTarget=Towers>>popDiskFrom:
Time for compilation : count= 12, sum= 9361, min= 33, average= 780.09, max= 3424 (milliseconds), maxTarget=Benchmark>>innerBenchmarkLoop:
Truffle Tier : count= 12, sum= 5915, min= 29, average= 492.97, max= 1672 (milliseconds), maxTarget=Benchmark>>innerBenchmarkLoop:
Graal Tier : count= 12, sum= 2264, min= 1, average= 188.72, max= 1131 (milliseconds), maxTarget=Benchmark>>innerBenchmarkLoop:
Code Installation : count= 12, sum= 1180, min= 1, average= 98.39, max= 620 (milliseconds), maxTarget=Benchmark>>innerBenchmarkLoop:
Truffle node count : count= 12, sum= 18749, min= 19, average= 1562.42, max= 7679, maxTarget=Benchmark>>innerBenchmarkLoop:
Trivial : count= 12, sum= 7006, min= 8, average= 583.83, max= 2859, maxTarget=Benchmark>>innerBenchmarkLoop:
Non Trivial : count= 12, sum= 11743, min= 11, average= 978.58, max= 4820, maxTarget=Benchmark>>innerBenchmarkLoop:
Monomorphic : count= 12, sum= 11469, min= 11, average= 955.75, max= 4715, maxTarget=Benchmark>>innerBenchmarkLoop:
Polymorphic : count= 12, sum= 274, min= 0, average= 22.83, max= 105, maxTarget=Benchmark>>innerBenchmarkLoop:
Megamorphic : count= 12, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=TowersDisk>>next:
Truffle call count : count= 12, sum= 220, min= 0, average= 18.33, max= 93, maxTarget=Benchmark>>innerBenchmarkLoop:
Indirect : count= 12, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=TowersDisk>>next:
Direct : count= 12, sum= 220, min= 0, average= 18.33, max= 93, maxTarget=Benchmark>>innerBenchmarkLoop:
Dispatched : count= 12, sum= 21, min= 0, average= 1.75, max= 8, maxTarget=Benchmark>>innerBenchmarkLoop:
Inlined : count= 12, sum= 199, min= 0, average= 16.58, max= 85, maxTarget=Benchmark>>innerBenchmarkLoop:
---------- :
Cloned : count= 12, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=TowersDisk>>next:
Not Cloned : count= 12, sum= 220, min= 0, average= 18.33, max= 93, maxTarget=Benchmark>>innerBenchmarkLoop:
Truffle loops : count= 12, sum= 0, min= 0, average= 0.00, max= 0, maxTarget=TowersDisk>>next:
Graal node count :
After Truffle Tier : count= 12, sum= 15050, min= 25, average= 1254.17, max= 4760, maxTarget=Benchmark>>innerBenchmarkLoop:
After Graal Tier : count= 12, sum= 43033, min= 26, average= 3586.08, max= 17117, maxTarget=Benchmark>>innerBenchmarkLoop:
Graal compilation result :
Code size : count= 12, sum= 147588, min= 216, average= 12299.00, max= 54825, maxTarget=Benchmark>>innerBenchmarkLoop:
Total frame size : count= 12, sum= 1968, min= 32, average= 164.00, max= 448, maxTarget=Towers>>move:disksFrom:to:
Exception handlers : count= 12, sum= 25, min= 0, average= 2.08, max= 15, maxTarget=Benchmark>>innerBenchmarkLoop:
Infopoints : count= 12, sum= 1644, min= 4, average= 137.00, max= 645, maxTarget=Benchmark>>innerBenchmarkLoop:
CALL : count= 12, sum= 1313, min= 4, average= 109.42, max= 506, maxTarget=Benchmark>>innerBenchmarkLoop:
IMPLICIT_EXCEPTION : count= 12, sum= 322, min= 0, average= 26.83, max= 138, maxTarget=Benchmark>>innerBenchmarkLoop:
SAFEPOINT : count= 12, sum= 9, min= 0, average= 0.75, max= 4, maxTarget=Towers>>buildTowerAt:disks:
Marks : count= 12, sum= 122, min= 7, average= 10.17, max= 23, maxTarget=Benchmark>>innerBenchmarkLoop:
Data references : count= 12, sum= 1018, min= 3, average= 84.83, max= 427, maxTarget=Benchmark>>innerBenchmarkLoop:
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment