Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

30% regression in creating string from integer from 1.10.2 to 1.11 #53950

Closed
Zentrik opened this issue Apr 4, 2024 · 2 comments · Fixed by #53962
Closed

30% regression in creating string from integer from 1.10.2 to 1.11 #53950

Zentrik opened this issue Apr 4, 2024 · 2 comments · Fixed by #53962
Labels
performance Must go faster regression Regression in behavior compared to a previous version
Milestone

Comments

@Zentrik
Copy link
Member

Zentrik commented Apr 4, 2024

On 1.10.2

julia> @benchmark string(1)
BenchmarkTools.Trial: 10000 samples with 995 evaluations.
 Range (min  max):  30.631 ns   2.994 μs  ┊ GC (min  max): 0.00%  96.50%
 Time  (median):     33.159 ns              ┊ GC (median):    0.00%
 Time  (mean ± σ):   36.987 ns ± 77.616 ns  ┊ GC (mean ± σ):  8.62% ±  4.14%

    ▁▃▅▆██▆▄▂▁                                                ▂
  ▄▇██████████▇▇▇▇▅▅▅▄▅▅▅▄▆▅▅▅▅▅▅▅▅▅▅▅▅▆▅▄▅▅▅▆▆▅▄▅▂▅▅▅▅▅▄▄▅▄▄ █
  30.6 ns      Histogram: log(frequency) by time      51.7 ns <

 Memory estimate: 88 bytes, allocs estimate: 2.

And on 1.11.0-alpha2

julia> @benchmark string(1)
BenchmarkTools.Trial: 10000 samples with 991 evaluations.
 Range (min  max):  41.866 ns   13.625 μs  ┊ GC (min  max):  0.00%  99.15%
 Time  (median):     44.646 ns               ┊ GC (median):     0.00%
 Time  (mean ± σ):   68.537 ns ± 309.203 ns  ┊ GC (mean ± σ):  12.39% ±  2.96%

  ▃▄█▆▃                                        ▁▃▃▄▄▅▄▄▃▃▂▁▁   ▂
  ██████▇▆▆▅▅▆▅▇▆▆▇▅▅▅▆▄▅▁▄▅▁▃▁▁▁▁▁▁▁▃▃▄▃▃▃▃▁▆███████████████▇ █
  41.9 ns       Histogram: log(frequency) by time      95.9 ns <

 Memory estimate: 88 bytes, allocs estimate: 3.
@jishnub jishnub added the regression Regression in behavior compared to a previous version label Apr 4, 2024
@oscardssmith oscardssmith added the performance Must go faster label Apr 4, 2024
@oscardssmith oscardssmith added this to the 1.11 milestone Apr 4, 2024
@abraemer
Copy link

abraemer commented Apr 5, 2024

I am not sure whether this a real effect or might be a benchmarking artifact. Changing @benchmark string(1) to @benchmark string($1) closes the performance gap for me.

On 1.10.2

julia> @benchmark string(1)
BenchmarkTools.Trial: 10000 samples with 996 evaluations.
 Range (min  max):  23.842 ns   3.270 μs  ┊ GC (min  max): 0.00%  97.17%
 Time  (median):     26.437 ns              ┊ GC (median):    0.00%
 Time  (mean ± σ):   29.703 ns ± 59.374 ns  ┊ GC (mean ± σ):  7.56% ±  4.05%

     ▂▄▅▇█▆▇▆▄▄▃▁▂▁ ▁              ▁  ▁▁ ▁                    ▂
  ▅▆▆██████████████▅██▇█▇▄▅▇▁▆▆▅██▇████████▆████▇▆▆▄▄▅▃▄▁▄▁▅▃ █
  23.8 ns      Histogram: log(frequency) by time      42.6 ns <

 Memory estimate: 88 bytes, allocs estimate: 2.

julia> @benchmark string($1)
BenchmarkTools.Trial: 10000 samples with 993 evaluations.
 Range (min  max):  35.309 ns    9.714 μs  ┊ GC (min  max):  0.00%  98.67%
 Time  (median):     38.333 ns               ┊ GC (median):     0.00%
 Time  (mean ± σ):   48.626 ns ± 177.734 ns  ┊ GC (mean ± σ):  12.80% ±  3.77%

   ▃███▆▄▃▂▁                                    ▁▂▂▃▂▃▁▂▁▁▁ ▁  ▂
  ▇███████████▆▅▆▅▅▇▇▇▆▄▅▁▅▄▅▅▄▅▅▅▅▅▄▆▅▅▄▄▅▄▄▅▇██████████████▇ █
  35.3 ns       Histogram: log(frequency) by time        80 ns <

 Memory estimate: 88 bytes, allocs estimate: 3.

On 1.11.0-alpha2

julia> @benchmark string(1)
BenchmarkTools.Trial: 10000 samples with 993 evaluations.
 Range (min  max):  32.635 ns    4.784 μs  ┊ GC (min  max):  0.00%  97.72%
 Time  (median):     37.278 ns               ┊ GC (median):     0.00%
 Time  (mean ± σ):   46.792 ns ± 142.570 ns  ┊ GC (mean ± σ):  17.50% ±  5.82%

  ▁▃▆▇▆▇█▇█▇▅▄▃▃▂▂▂▁▂▁▁▁▁                                ▁     ▃
  ████████████████████████▇▅▆▁▅▄▄▅▅▅▅▅▆▄▄▅▇▅▅▅▄▆▆▅▅▅▆▇▇█▇█████ █
  32.6 ns       Histogram: log(frequency) by time      70.8 ns <

 Memory estimate: 88 bytes, allocs estimate: 3.

julia> @benchmark string($1)
BenchmarkTools.Trial: 10000 samples with 992 evaluations.
 Range (min  max):  34.921 ns    4.188 μs  ┊ GC (min  max):  0.00%  97.67%
 Time  (median):     39.005 ns               ┊ GC (median):     0.00%
 Time  (mean ± σ):   48.287 ns ± 152.444 ns  ┊ GC (mean ± σ):  14.39% ±  4.54%

    ▃▆█▇▇▆▄▃▂▁     ▁                                           ▂
  ▄▄███████████████████▇▇▆▆▅▅▆▅▅▅▄▅▅▅▅▄▃▅▂▄▃▅▂▄▄▆▆▇███▇█▇▇▆▇▇▆ █
  34.9 ns       Histogram: log(frequency) by time      79.1 ns <

 Memory estimate: 88 bytes, allocs estimate: 3.

Edit: I reran the benchmarks with interpolation a couple of times to get a rough feeling for the timing fluctuations. On 1.10.2 the median is rather stable at 36.2ns and the minimal time fluctuates around 31ns within +-1ns. On 1.11.0-alpha2 the median fluctuates around 38ns (+- 1ns) and the minimal value fluctuates around 35ns (+- 1ns). So it seems that there might be a performance regression after all but more on the order of 10-15%.

@Zentrik
Copy link
Member Author

Zentrik commented Apr 5, 2024

I do see that with interpolation the gap narrows but it doesn't disappear. As the gc is at play here, maybe it's better to look at the mean. Also, included the original function I had that experienced the slowdown:
On 1.10.2

julia> @benchmark string($1)
BenchmarkTools.Trial: 10000 samples with 995 evaluations.
 Range (min  max):  33.367 ns   1.972 μs  ┊ GC (min  max): 0.00%  95.96%
 Time  (median):     38.392 ns              ┊ GC (median):    0.00%
 Time  (mean ± σ):   42.850 ns ± 79.872 ns  ┊ GC (mean ± σ):  7.94% ±  4.17%

         ▂▄▆▇█▇▆▄▃▂▂▁▁▁▁▁▂▁▂▁                           ▁▁▁   ▂
  ▄▁▄▅▄▆██████████████████████▇▇▇▆▆▅▄▅▄▁▃▁▁▁▃▃▁▁▃▃▃▄▅▅▇██████ █
  33.4 ns      Histogram: log(frequency) by time      58.1 ns <

 Memory estimate: 88 bytes, allocs estimate: 2.
julia> @benchmark string($(Ref(1))[]) samples=10^5
BenchmarkTools.Trial: 100000 samples with 994 evaluations.
 Range (min  max):  33.501 ns   2.570 μs  ┊ GC (min  max): 0.00%  96.66%
 Time  (median):     38.632 ns              ┊ GC (median):    0.00%
 Time  (mean ± σ):   42.519 ns ± 79.730 ns  ┊ GC (mean ± σ):  7.95% ±  4.15%

                 ▄▆█▇
  ▂▁▂▂▂▂▂▂▂▂▃▃▄▄███████▅▄▃▃▃▂▃▃▃▃▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂ ▃
  33.5 ns         Histogram: frequency by time        50.4 ns <

 Memory estimate: 88 bytes, allocs estimate: 2.
julia> function test()
           for i in 1:10^6
               string(i)
           end
       end
test (generic function with 1 method)

julia> @benchmark test()
BenchmarkTools.Trial: 119 samples with 1 evaluation.
 Range (min  max):  40.037 ms   44.620 ms  ┊ GC (min  max): 4.33%  10.02%
 Time  (median):     42.104 ms               ┊ GC (median):    8.24%
 Time  (mean ± σ):   42.149 ms ± 793.115 μs  ┊ GC (mean ± σ):  8.03% ±  1.14%

                           ██▅▇ ▄
  ▃▃▅▄▄▁▁▁▁▃▁▁▁▁▁▁▁▁▁▁▁▁▁▆▇██████▆▅▁▃▁▁▃▁▃▁▃▁▃▁▁▁▁▃▁▅▄▁▃▁▁▁▁▁▃ ▃
  40 ms           Histogram: frequency by time         44.6 ms <

 Memory estimate: 83.92 MiB, allocs estimate: 2000000.

On 1.11.0-alpha2

julia> @benchmark string($1)
BenchmarkTools.Trial: 10000 samples with 992 evaluations.
 Range (min  max):  38.609 ns   10.055 μs  ┊ GC (min  max):  0.00%  99.06%
 Time  (median):     43.548 ns               ┊ GC (median):     0.00%
 Time  (mean ± σ):   56.230 ns ± 228.670 ns  ┊ GC (mean ± σ):  11.10% ±  2.80%

     ▅█
  ▂▄▇███▄▃▃▂▂▂▂▂▂▂▂▂▂▂▂▃▅▆▆▅▃▃▂▂▂▂▂▂▂▂▂▂▂▂▂▂▁▁▂▂▁▂▂▁▂▁▂▂▂▂▂▂▂▂ ▃
  38.6 ns         Histogram: frequency by time         98.1 ns <

 Memory estimate: 88 bytes, allocs estimate: 3.

julia> @benchmark string($(Ref(1))[]) samples=10^5
BenchmarkTools.Trial: 89958 samples with 996 evaluations.
 Range (min  max):  37.751 ns    9.949 μs  ┊ GC (min  max):  0.00%  99.12%
 Time  (median):     43.675 ns               ┊ GC (median):     0.00%
 Time  (mean ± σ):   54.546 ns ± 230.341 ns  ┊ GC (mean ± σ):  18.21% ±  4.31%

          ▃▂▂▂▃█▅
  ▁▁▁▂▃▃▃▆███████▇▅▃▂▂▂▂▂▂▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁ ▂
  37.8 ns         Histogram: frequency by time           66 ns <

 Memory estimate: 88 bytes, allocs estimate: 3.

julia> function test()
           for i in 1:10^6
               string(i)
           end
       end
test (generic function with 1 method)

julia> @benchmark test()
BenchmarkTools.Trial: 87 samples with 1 evaluation.
 Range (min  max):  50.611 ms  69.290 ms  ┊ GC (min  max):  0.00%  14.27%
 Time  (median):     56.535 ms              ┊ GC (median):    17.61%
 Time  (mean ± σ):   57.575 ms ±  2.834 ms  ┊ GC (mean ± σ):  17.75% ±  3.81%

                     ▃█▆
  ▅▁▁▁▅▁▅▁▁▁▁▁▁▁▁▁▁▅▅████▅▁▁▅▅▁█▅█▁▁▅▅▁▅██▅▁▅▁▁▁▁▅▁▁▅▁▁▁▁▁▁▁▅ ▁
  50.6 ms      Histogram: log(frequency) by time      67.1 ms <

 Memory estimate: 83.92 MiB, allocs estimate: 3000000.

Zentrik added a commit to Zentrik/julia that referenced this issue Apr 5, 2024
On `1.11.0-alpha2`
Old:
```julia
@benchmark Base.dec($0x1, $0, $false)
BenchmarkTools.Trial: 10000 samples with 994 evaluations.
 Range (min … max):  33.702 ns …   4.242 μs  ┊ GC (min … max):  0.00% … 97.61%
 Time  (median):     37.626 ns               ┊ GC (median):     0.00%
 Time  (mean ± σ):   45.787 ns ± 147.794 ns  ┊ GC (mean ± σ):  14.53% ±  4.47%

    ▄▅▆▇█▇▇▅▃▃▂▂▂▁    ▁▂▁▁▁             ▁▁   ▁                 ▂
  ▄▇███████████████▇▇██████▇█▆▆▄▄▃▄▅▄▆▇████████▆▅▅▇▆▅▆▄▄▅▄▄▄▁▅ █
  33.7 ns       Histogram: log(frequency) by time      67.5 ns <

 Memory estimate: 88 bytes, allocs estimate: 3.
```
New:
```julia
BenchmarkTools.Trial: 10000 samples with 995 evaluations.
 Range (min … max):  27.538 ns …   3.397 μs  ┊ GC (min … max):  0.00% … 97.86%
 Time  (median):     30.151 ns               ┊ GC (median):     0.00%
 Time  (mean ± σ):   34.547 ns ± 105.101 ns  ┊ GC (mean ± σ):  10.37% ±  3.39%

       ▁ █▆▃  ▁
  ▂▂▃▃▅█████▆████▆▄▄▃▃▃▃▃▃▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▁▂▂▂▂▂▁▂▂▂▂▂▂▂▂▂▂▂▂▂ ▃
  27.5 ns         Histogram: frequency by time         43.8 ns <

 Memory estimate: 56 bytes, allocs estimate: 2.
```


Fixes JuliaLang#53950, actually now even faster than `1.10.2`.
oscardssmith pushed a commit that referenced this issue Apr 5, 2024
On `1.11.0-alpha2`
Old:
```julia
@benchmark Base.dec($0x1, $0, $false)
BenchmarkTools.Trial: 10000 samples with 994 evaluations.
 Range (min … max):  33.702 ns …   4.242 μs  ┊ GC (min … max):  0.00% … 97.61%
 Time  (median):     37.626 ns               ┊ GC (median):     0.00%
 Time  (mean ± σ):   45.787 ns ± 147.794 ns  ┊ GC (mean ± σ):  14.53% ±  4.47%

    ▄▅▆▇█▇▇▅▃▃▂▂▂▁    ▁▂▁▁▁             ▁▁   ▁                 ▂
  ▄▇███████████████▇▇██████▇█▆▆▄▄▃▄▅▄▆▇████████▆▅▅▇▆▅▆▄▄▅▄▄▄▁▅ █
  33.7 ns       Histogram: log(frequency) by time      67.5 ns <

 Memory estimate: 88 bytes, allocs estimate: 3.
```
New:
```julia
BenchmarkTools.Trial: 10000 samples with 995 evaluations.
 Range (min … max):  27.538 ns …   3.397 μs  ┊ GC (min … max):  0.00% … 97.86%
 Time  (median):     30.151 ns               ┊ GC (median):     0.00%
 Time  (mean ± σ):   34.547 ns ± 105.101 ns  ┊ GC (mean ± σ):  10.37% ±  3.39%

       ▁ █▆▃  ▁
  ▂▂▃▃▅█████▆████▆▄▄▃▃▃▃▃▃▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▁▂▂▂▂▂▁▂▂▂▂▂▂▂▂▂▂▂▂▂ ▃
  27.5 ns         Histogram: frequency by time         43.8 ns <

 Memory estimate: 56 bytes, allocs estimate: 2.
```


Fixes #53950, actually now even faster than `1.10.2`.

It doesn't look like the length is ever changed and we don't return
these `StringMemory`s so this change should be fine.
KristofferC pushed a commit that referenced this issue Apr 9, 2024
On `1.11.0-alpha2`
Old:
```julia
@benchmark Base.dec($0x1, $0, $false)
BenchmarkTools.Trial: 10000 samples with 994 evaluations.
 Range (min … max):  33.702 ns …   4.242 μs  ┊ GC (min … max):  0.00% … 97.61%
 Time  (median):     37.626 ns               ┊ GC (median):     0.00%
 Time  (mean ± σ):   45.787 ns ± 147.794 ns  ┊ GC (mean ± σ):  14.53% ±  4.47%

    ▄▅▆▇█▇▇▅▃▃▂▂▂▁    ▁▂▁▁▁             ▁▁   ▁                 ▂
  ▄▇███████████████▇▇██████▇█▆▆▄▄▃▄▅▄▆▇████████▆▅▅▇▆▅▆▄▄▅▄▄▄▁▅ █
  33.7 ns       Histogram: log(frequency) by time      67.5 ns <

 Memory estimate: 88 bytes, allocs estimate: 3.
```
New:
```julia
BenchmarkTools.Trial: 10000 samples with 995 evaluations.
 Range (min … max):  27.538 ns …   3.397 μs  ┊ GC (min … max):  0.00% … 97.86%
 Time  (median):     30.151 ns               ┊ GC (median):     0.00%
 Time  (mean ± σ):   34.547 ns ± 105.101 ns  ┊ GC (mean ± σ):  10.37% ±  3.39%

       ▁ █▆▃  ▁
  ▂▂▃▃▅█████▆████▆▄▄▃▃▃▃▃▃▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▁▂▂▂▂▂▁▂▂▂▂▂▂▂▂▂▂▂▂▂ ▃
  27.5 ns         Histogram: frequency by time         43.8 ns <

 Memory estimate: 56 bytes, allocs estimate: 2.
```

Fixes #53950, actually now even faster than `1.10.2`.

It doesn't look like the length is ever changed and we don't return
these `StringMemory`s so this change should be fine.

(cherry picked from commit 0e59c9e)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
performance Must go faster regression Regression in behavior compared to a previous version
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants