enso-org / enso

Hybrid visual and textual functional programming.
https://enso.org
Apache License 2.0
7.33k stars 320 forks source link

Up to 200% benchmarks regression after integrating `Comparable.from` return type check #10539

Closed JaroslavTulach closed 1 month ago

JaroslavTulach commented 1 month ago

Recent integration of

caused some improvements, but also some regressions that deserve to be evaluated properly:

I knew about the Max_Stats regression, but decided to integrated #10355 anyway to fix the Comparable.from inconsistency. Now the time has come to address (or at least analyze) also the performance regression.

JaroslavTulach commented 1 month ago

When analyzing the graphs from

sbt:std-benchmarks> withDebug --dumpGraphs benchOnly -- Max_Stats

I noticed a code dedicated to EnsoMultiValue - that's quite useless as there is no EnsoMultiValue:

EnsoMultiValue

This is addressed by https://github.com/enso-org/enso/commit/a23b8771033e796c6f452ab161cd5471c2a90c49

JaroslavTulach commented 1 month ago

The Max_Stats benchmark seems to oscillate quite a lot:

Max_Stats benchmark

I assume that's because of insufficient warmup.

enso-bot[bot] commented 1 month ago

Jaroslav Tulach reports a new STANDUP for yesterday (2024-07-17):

Progress: - verifying outputstream benchmarks

Discord
Discord - Group Chat That’s All Fun & Games
Discord is great for playing games and chilling with friends, or even building a worldwide community. Customize your own space to talk, play, and hang out.
JaroslavTulach commented 1 month ago

Comparing the two runs of benchOnly Max_Stats in VisualVM. This is the slow run on top of 2024.3.1-nightly.2024.7.11.1:

slow run

and this is the original, fast run on 2024.3.1-nightly.2024.7.11:

fast run

Run Accumulator.increment Line 377 Line 383 Line 378
fast 53% 23,5% 15,3% 11,5%
slow 76,9% 33,4% 5,3% 35,9%

When we normalize the overall percentage we see which line occupies the most from the Accumulator.increment run:

Run Line 377 Line 383 Line 378
fast 44,3% 28,8% 21,6%
slow 43,3% 6,8% 46,6%

we can see that the biggest slowdown is on line 378 and also line 377 is twice as slow given the benchmark takes at least twice as much time and the percentage remains the same. Line 383 is running fast or even faster than it used to.

JaroslavTulach commented 1 month ago

One way to speed Max_Stats benchmark up is to:

enso$ git diff distribution/lib/Standard/Base/0.0.0-dev/src/Data/Statistics.enso
diff --git distribution/lib/Standard/Base/0.0.0-dev/src/Data/Statistics.enso distribution/lib/Standard/Base/0.0.0-dev/src/Data/Statistics.enso
index c5008cd51e..e58c402f65 100644
--- distribution/lib/Standard/Base/0.0.0-dev/src/Data/Statistics.enso
+++ distribution/lib/Standard/Base/0.0.0-dev/src/Data/Statistics.enso
@@ -385,7 +385,7 @@ type Accumulator
     ## PRIVATE
     perform_comparison current value bound =
         comp = Ordering.compare value current
-        if comp == bound then value else current
+        if Meta.is_same_object comp bound then value else current

     ## PRIVATE
     update_moments self value = if self.moments.is_nothing then Nothing else

the next question: How to speed it up without Meta.is_same_object unnatural trick? The answer is in #10593

JaroslavTulach commented 1 month ago

this is the original, fast run on 2024.3.1-nightly.2024.7.11:

fast run

most recent run

I guess the most recent run is even faster! The distribution of load is on the same lines and most of them seem to run even faster.

enso-bot[bot] commented 1 month ago

Jaroslav Tulach reports a new STANDUP for yesterday (2024-07-18):

Progress: - found a way to speed Max_Stats: https://github.com/enso-org/enso/issues/10539#issuecomment-2235896056

Discord
Discord - Group Chat That’s All Fun & Games
Discord is great for playing games and chilling with friends, or even building a worldwide community. Customize your own space to talk, play, and hang out.
JaroslavTulach commented 1 month ago
Benchmark: org.enso.benchmarks.generated.Time_Work_Days_Shift_100.add_work_days
Run progress: 73.59% complete, ETA 00:33:26
Warmup Iteration   1: 255.248 ms/op
Before WARMUP#1. Cleaning 137 compilation messages
Before MEASUREMENT#1. Cleaning 451 compilation messages
After MEASUREMENT#1. Dumping 45 compilation messages:
opt done   id=3872  Vector.at                                          |Tier 2|Time    66(  39+28  )ms|AST   59|Inlined   0Y   0N|IR    468/  1334|CodeSize    5401|Addr 0x7f7ff393fc80|Timestamp 6489699047327812|Src Vector.enso:301
opt done   id=2684  Standard.Base.Data.Time.Period.Period.Value        |Tier 2|Time     2(   1+1   )ms|AST    1|Inlined   0Y   0N|IR     17/    20|CodeSize     188|Addr 0x7f7ff3942700|Timestamp 6489699049710392|Src n/a
opt done   id=2683  Period.Value                                       |Tier 2|Time     9(   6+3   )ms|AST   20|Inlined   0Y   0N|IR     95/   282|CodeSize    1235|Addr 0x7f7ff3942a60|Timestamp 6489699083909972|Src Period.enso:83
opt done   id=6781  Period.type.new                                    |Tier 2|Time    73(  43+30  )ms|AST   45|Inlined   3Y   0N|IR    414/   953|CodeSize    4148|Addr 0x7f7ff3943600|Timestamp 6489699084589635|Src Period.enso:75
opt done   id=2685  internal_period                                    |Tier 2|Time     3(   1+2   )ms|AST    4|Inlined   0Y   0N|IR     39/   103|CodeSize     652|Addr 0x7f7ff3946820|Timestamp 6489699086889262|Src n/a
opt done   id=4040  Range.fold.go<arg-1>                               |Tier 2|Time     9(   5+3   )ms|AST   19|Inlined   1Y   0N|IR    125/   262|CodeSize    1228|Addr 0x7f7ff3946e40|Timestamp 6489699093508206|Src Range.enso:331
opt done   id=4036  Range.fold.end_condition                           |Tier 2|Time    17(  16+2   )ms|AST   26|Inlined   1Y   0N|IR     30/    69|CodeSize     449|Addr 0x7f7ff39477a0|Timestamp 6489699104412876|Src Range.enso:329
opt done   id=4032  Range.fold<arg-0>                                  |Tier 2|Time    15(  12+2   )ms|AST   22|Inlined   3Y   0N|IR    136/    88|CodeSize     498|Addr 0x7f7ff3947d20|Timestamp 6489699108487076|Src Range.enso:328
opt done   id=4034  Range.fold<arg-0>                                  |Tier 2|Time     8(   5+3   )ms|AST   19|Inlined   1Y   0N|IR    116/   223|CodeSize    1038|Addr 0x7f7ff39482c0|Timestamp 6489699118880033|Src Range.enso:329
opt done   id=4037  Range.fold<arg-1>                                  |Tier 2|Time     8(   1+7   )ms|AST    2|Inlined   0Y   0N|IR     34/   541|CodeSize    1964|Addr 0x7f7ff3948b60|Timestamp 6489699127186752|Src Range.enso:329
opt done   id=4035  Range.fold<arg-0>                                  |Tier 2|Time    22(  20+2   )ms|AST   22|Inlined   3Y   0N|IR    145/   133|CodeSize     671|Addr 0x7f7ff3949720|Timestamp 6489699130767543|Src Range.enso:329
opt done   id=4046  Range.fold<arg-1>                                  |Tier 2|Time     8(   5+3   )ms|AST   19|Inlined   1Y   0N|IR    107/   184|CodeSize     876|Addr 0x7f7ff3949e40|Timestamp 6489699135157730|Src Range.enso:334
opt done   id=3991  Array_Like_Helpers.map.Array_Like_Helpers.map<arg-0> |Tier 2|Time    84(  34+50  )ms|AST   22|Inlined   1Y   0N|IR    581/  1556|CodeSize    6412|Addr 0x7f7ff394a720|Timestamp 6489699175360739|Src Array_Like_Helpers.enso:261
opt done   id=4024  Array_Like_Helpers.fold<arg-0>                     |Tier 2|Time   113( 109+4   )ms|AST   22|Inlined   7Y   0N|IR    265/   132|CodeSize     684|Addr 0x7f7ff394ddc0|Timestamp 6489699288250653|Src Array_Like_Helpers.enso:271
opt done   id=3799  Range.is_empty                                     |Tier 2|Time   114( 110+4   )ms|AST   28|Inlined  10Y   0N|IR    365/    85|CodeSize     497|Addr 0x7f7ff394e520|Timestamp 6489699402925001|Src Range.enso:155
opt done   id=3787  Range.length                                       |Tier 2|Time   272( 268+5   )ms|AST   29|Inlined  32Y   0N|IR   1109/   205|CodeSize     832|Addr 0x7f7ff3959820|Timestamp 6489699675442450|Src Range.enso:97
opt done   id=4020  Array_Like_Helpers.fold                            |Tier 2|Time  2097( 537+1560)ms|AST   36|Inlined  61Y   3N|IR   4582/ 10690|CodeSize   46604|Addr 0x7f7ff395d620|Timestamp 6489701232317730|Src Array_Like_Helpers.enso:269
opt done   id=3021  Standard.Base.Data.Time.Day_Of_Week.Day_Of_Week.Saturday |Tier 2|Time     2(   2+1   )ms|AST    1|Inlined   0Y   0N|IR     17/    20|CodeSize     188|Addr 0x7f7ff397fe80|Timestamp 6489701235106887|Src n/a
opt done   id=7117  case_branch<arg-3>                                 |Tier 2|Time     4(   1+3   )ms|AST    2|Inlined   0Y   0N|IR     34/   541|CodeSize    1964|Addr 0x7f7ff3980760|Timestamp 6489701239494235|Src Filter_Condition.enso:155
opt done   id=7115  case_branch<arg-2>                                 |Tier 2|Time    26(  12+14  )ms|AST   14|Inlined   1Y   0N|IR    412/  1179|CodeSize    4796|Addr 0x7f7ff3981440|Timestamp 6489701265416729|Src Filter_Condition.enso:155
opt done   id=7116  case_branch.case <internal-2496>                   |Tier 2|Time     4(   2+2   )ms|AST    7|Inlined   0Y   0N|IR    100/   165|CodeSize     838|Addr 0x7f7ff3984120|Timestamp 6489701269988687|Src Filter_Condition.enso:155
opt done   id=7112  case_branch                                        |Tier 2|Time     3(   2+1   )ms|AST    7|Inlined   0Y   0N|IR     73/    61|CodeSize     413|Addr 0x7f7ff3984820|Timestamp 6489701273141773|Src Filter_Condition.enso:301
opt done   id=1140  elements_java_builder                              |Tier 2|Time     3(   1+2   )ms|AST    4|Inlined   0Y   0N|IR     39/   103|CodeSize     652|Addr 0x7f7ff39851a0|Timestamp 6489701292671726|Src n/a
opt done   id=1141  propagate_warnings                                 |Tier 2|Time     2(   1+1   )ms|AST    4|Inlined   0Y   0N|IR     39/   104|CodeSize     652|Addr 0x7f7ff39857a0|Timestamp 6489701295028025|Src n/a
opt done   id=1142  warnings_java_builder                              |Tier 2|Time     2(   1+1   )ms|AST    4|Inlined   0Y   0N|IR     39/   104|CodeSize     652|Addr 0x7f7ff3985da0|Timestamp 6489701297465541|Src n/a
opt done   id=6780  Date.+                                             |Tier 2|Time   127(  55+72  )ms|AST   42|Inlined   5Y   0N|IR    626/   697|CodeSize    3441|Addr 0x7f7ff398aae0|Timestamp 6489701424446965|Src Date.enso:522
opt done   id=3733  Vector.type.build<arg-2>                           |Tier 2|Time     8(   1+6   )ms|AST    2|Inlined   0Y   0N|IR     34/   541|CodeSize    1964|Addr 0x7f7ff398d460|Timestamp 6489701432246578|Src Vector.enso:193
opt done   id=3736  Vector.type.build_multiple<arg-0>                  |Tier 2|Time    39(  35+4   )ms|AST   21|Inlined   1Y   0N|IR     30/    60|CodeSize     339|Addr 0x7f7ff3992300|Timestamp 6489701471626401|Src Vector.enso:245
opt done   id=4018  Vector.fold                                        |Tier 2|Time  2404( 550+1854)ms|AST   33|Inlined  61Y   4N|IR   4592/ 10886|CodeSize   46470|Addr 0x7f7ff3995580|Timestamp 6489701535215713|Src Vector.enso:335
opt done   id=3755  Range.type.new<arg-0>                              |Tier 2|Time    38(  36+2   )ms|AST   36|Inlined   5Y   0N|IR     68/   135|CodeSize     626|Addr 0x7f7ff39baea0|Timestamp 6489701573535777|Src Range.enso:32
opt done   id=3752  Range.type.new                                     |Tier 2|Time   185( 180+5   )ms|AST   50|Inlined  27Y   0N|IR    190/   295|CodeSize    1190|Addr 0x7f7ff39bb560|Timestamp 6489701661636327|Src Range.enso:31
opt done   id=3744  Vector.type.build_multiple<arg-0>                  |Tier 2|Time     5(   3+2   )ms|AST   17|Inlined   0Y   0N|IR     24/   164|CodeSize     668|Addr 0x7f7ff39bc6a0|Timestamp 6489701667120638|Src Vector.enso:247
opt done   id=3743  Vector.type.build_multiple<arg-1>                  |Tier 2|Time     4(   1+4   )ms|AST    2|Inlined   0Y   0N|IR     34/   541|CodeSize    1964|Addr 0x7f7ff39bcce0|Timestamp 6489701671505803|Src Vector.enso:246
opt done   id=3741  Vector.type.build_multiple<arg-0>                  |Tier 2|Time   225( 222+3   )ms|AST   23|Inlined  28Y   0N|IR     65/   168|CodeSize     780|Addr 0x7f7ff39bd8c0|Timestamp 6489701696468947|Src Vector.enso:246
opt done   id=3852  Builder.type.new<arg-2>                            |Tier 2|Time     6(   4+1   )ms|AST   22|Inlined   0Y   0N|IR     20/    60|CodeSize     345|Addr 0x7f7ff39be020|Timestamp 6489701727127362|Src Vector.enso:1331
opt done   id=3785  Range.map<arg-2>                                   |Tier 2|Time     4(   1+4   )ms|AST    2|Inlined   0Y   0N|IR     34/   541|CodeSize    1964|Addr 0x7f7ff39be4e0|Timestamp 6489701731497489|Src Range.enso:184
opt done   id=3784  Range.map.Range.map                                |Tier 2|Time   156(  89+67  )ms|AST   18|Inlined  14Y   0N|IR   1262/  2322|CodeSize   11129|Addr 0x7f7ff39c0c60|Timestamp 6489701887744364|Src Range.enso:184
opt done   id=3869  Nothing.if_nothing                                 |Tier 2|Time     8(   6+2   )ms|AST   10|Inlined   1Y   0N|IR     40/   202|CodeSize     879|Addr 0x7f7ff39c6bc0|Timestamp 6489701895938352|Src Nothing.enso:34
opt done   id=3779  Range.map<arg-1>                                   |Tier 2|Time   200( 195+5   )ms|AST   19|Inlined  33Y   0N|IR   1183/   249|CodeSize     876|Addr 0x7f7ff39c7320|Timestamp 6489701896610973|Src Range.enso:184
opt done   id=3868  Panic.type.handle_wrapped_dataflow_error<arg-3>    |Tier 2|Time     4(   1+4   )ms|AST    2|Inlined   0Y   0N|IR     34/   541|CodeSize    1964|Addr 0x7f7ff39c7f60|Timestamp 6489701900398450|Src Panic.enso:256
opt done   id=3731  Vector.type.build.results_multiple<arg-0>          |Tier 2|Time    16(  13+3   )ms|AST   21|Inlined   1Y   0N|IR    242/   127|CodeSize     672|Addr 0x7f7ff39c8b40|Timestamp 6489701912978032|Src Vector.enso:193
opt done   id=4009  Builder.to_vector                                  |Tier 2|Time   511( 457+54  )ms|AST   65|Inlined  62Y   1N|IR   1466/  2640|CodeSize   11292|Addr 0x7f7ff39cc340|Timestamp 6489702424355984|Src Vector.enso:1515
opt done   id=3734  Vector.type.build<arg-1>                           |Tier 2|Time    16(  13+3   )ms|AST   21|Inlined   1Y   0N|IR    243/   126|CodeSize     672|Addr 0x7f7ff39d0dc0|Timestamp 6489702440685338|Src Vector.enso:194
opt done   id=3778  Range.map                                          |Tier 2|Time   941( 395+546 )ms|AST   31|Inlined  64Y   0N|IR   2881/  5148|CodeSize   25068|Addr 0x7f7ff39d1a00|Timestamp 6489702612946103|Src Range.enso:183
opt done   id=4163  Report_Error                                       |Tier 2|Time     6(   3+2   )ms|AST   14|Inlined   1Y   0N|IR     35/   192|CodeSize     847|Addr 0x7f7ff39e5840|Timestamp 6489702618866527|Src n/a
Iteration   1: 57.170 ms/op
Result "org.enso.benchmarks.generated.Time_Work_Days_Shift_100.add_work_days":