Improve printing of several arguments

[gdalle]

Following a discussion on Discourse, this PR tries to improve print (and variants) for more than one argument.
The idea is that for is type-unstable over the tuple args, while foreach unrolls. I have no idea how to properly evaluate the potential performance gains though.

[Tortar]

To test if it works I guess you could execute https://github.com/shagrouni/langs_string_build_test/blob/main/src/jl_strbld.jl with julia jl_strbld.jl 50000000 and see if it now works faster, it should be hopefully as fast as using

    ...
    for i in 1:num
        print(buf, " J ")
        print(buf, i)
    end
    ...

[gdalle]

Doesn't look half bad.

using BenchmarkTools

function test_slow(n::Integer)
    s = "hello"
    buf = IOBuffer()
    for i in 1:n
        print(buf, s, i)
    end
end

function test_fast(n::Integer)
    s = "hello"
    buf = IOBuffer()
    for i in 1:n
        print(buf, s)
        print(buf, i)
    end
end

@btime test_slow(50_000);
@btime test_fast(50_000);

Current nightly

julia> @btime test_slow(50_000);
  5.376 ms (249003 allocations: 7.35 MiB)

julia> @btime test_fast(50_000);
  2.959 ms (100025 allocations: 4.31 MiB)

This PR

julia> @btime test_slow(50_000);
  3.503 ms (100025 allocations: 4.31 MiB)

julia> @btime test_fast(50_000);
  3.018 ms (100025 allocations: 4.31 MiB)

[stevengj]

Ideally, test_slow and test_fast should now be equivalent.

@tkf, shouldn't foreach on a 2-tuple now be equivalent to a fully unrolled loop thanks to #31901? I suspect that there is some compiler specialization that is still missing.

(That doesn't need to block this PR, however — it's still faster, even if there are some opportunities for additionally speeding up foreach.)

[gdalle]

I think Takafumi is no longer around?

[Tortar]

Does the technique have any downside @stevengj such as increasing compile time substantially? Because otherwise this can probably be applied in other Vararg cases right?

[nsajko]

To make this PR complete, this:

julia/base/strings/io.jl

Lines 141 to 144 in 467ab85

	siz::Int = 0
	for x in xs
	siz += _str_sizehint(x)
	end

... and this:

julia/base/strings/io.jl

Lines 157 to 160 in 467ab85

	siz::Int = 0
	for x in xs
	siz += _str_sizehint(x)
	end

... should probably be deduplicated and reimplemented using mapreduce. Something like:

function _str_sizehints(xs...)
    mapreduce(_str_sizehint, +, xs; init = 0)
end

[gdalle]

Done!

[LilithHafner]

Thanks! I can reproduce those benchmarks and appreciate the performance improvement.

Does the technique have any downside stevengj such as increasing compile time substantially?

Compile time of test_slow does increase from 5ms to 9ms:

julia> compile_time(version) = parse(Float64, strip(read(`julia +$version -E 'function test_slow(n::Integer)
               s = "hello"
               buf = IOBuffer()
               for i in 1:n
                   print(buf, s, i)
               end
           end; @elapsed @eval test_slow(100)'`, String)))
compile_time (generic function with 1 method)

julia> [compile_time("nightly") for _ in 1:7]
7-element Vector{Float64}:
 0.005005201
 0.004923159
 0.004996992
 0.005025118
 0.004929617
 0.004938451
 0.004956284

julia> [compile_time("pr55754") for _ in 1:7]
7-element Vector{Float64}:
 0.009146896
 0.009284273
 0.009325356
 0.009385732
 0.009336814
 0.009289814
 0.009340064

shell> julia +nightly -E 'Base.GIT_VERSION_INFO.commit'
"467ab852bb7392843ce74a17de89c221e0f64df0"

shell> julia +pr55754 -E 'Base.GIT_VERSION_INFO.commit'
"b47a4940dc130e50795254f877a17a766be7d2fc"

[nsajko]

The _str_sizehints changes sadly break bootstrap for the assert builds.

gmp.jl
ryu/Ryu.jl
ryu/utils.jl
ryu/shortest.jl
Internal error: during type inference of
string(Expr)
Encountered unexpected error in runtime:
AssertionError(msg="irinterp is unable to handle heavy recursion")
collect_limitations! at ./compiler/ssair/irinterp.jl:4 [inlined]
from_interprocedural! at ./compiler/abstractinterpretation.jl:392 [inlined]

[gdalle]

The _str_sizehints changes sadly break bootstrap for the assert builds.

@nsajko what does that mean in layperson terms?

[nsajko]

The bootstrap (the initial compilation of Base and other code) fails because the compiler refuses to handle deep recursion. Or something like that.

In practice that probably means you have to revert the commit I suggested (I think the build was successful for the initial commit in the PR, right?). I guess we could try reintroducing the mapreduce after #55575 gets merged.

[vtjnash]

This adds a dynamic closure capture though and dispatch, which may not be performant

[JeffBezanson]

That error isn't supposed to happen; you may have found an interesting bug :)

[JeffBezanson]

If you update this, please keep a branch around with that failure so we can work on it.

[gdalle]

@vtjnash I think it comes down to a compromise between tuple unrolling (which is possible with foreach but not with for) and the additional closure required. My PR might be slower for printing tuples with identically typed arguments for instance. I just wanted to experiment with Steven's suggestion but I don't have strong feeling either way, so I'll let the knowledgeable people hash it out.

[stevengj]

What does the benchmark look like with the latest Fix1 version? Is it matching the manually unrolled 2-print-call version yet?

[gdalle]

No, the same difference remains.

Currently nightly

julia> @btime test_slow(50_000);
  5.245 ms (249003 allocations: 7.35 MiB)

julia> @btime test_fast(50_000);
  2.801 ms (100025 allocations: 4.31 MiB)

This PR

julia> @btime test_slow(50_000);
  3.622 ms (100025 allocations: 4.31 MiB)

julia> @btime test_fast(50_000);
  2.925 ms (100025 allocations: 4.31 MiB)

[LilithHafner]

Compile time regression is also gone!

julia> compile_time(version) = parse(Float64, strip(read(`julia +$version -E 'function test_slow(n::Integer)
               s = "hello"
               buf = IOBuffer()
               for i in 1:n
                   print(buf, s, i)
               end
           end; @elapsed @eval test_slow(100)'`, String)))
compile_time (generic function with 1 method)

julia> [compile_time("nightly") for _ in 1:7]
Juliaup configuration is locked by another process, waiting for it to unlock.
Juliaup configuration is locked by another process, waiting for it to unlock.
Juliaup configuration is locked by another process, waiting for it to unlock.
7-element Vector{Float64}:
 0.006195663
 0.005031322
 0.005418033
 0.005152656
 0.005105739
 0.005199073
 0.005210907

julia> [compile_time("pr55754") for _ in 1:7]
7-element Vector{Float64}:
 0.008983305
 0.005014739
 0.004937614
 0.005452533
 0.005186157
 0.005184865
 0.005381825

shell> julia +nightly -E 'Base.GIT_VERSION_INFO.commit'
"58b239c5b8eaffec3b9b99e6d7c37e8ae6129d6d"

shell> julia +pr55754 -E 'Base.GIT_VERSION_INFO.commit'
"91443de63550381d4d95d7b992e3d9de8206e8c3"

[gdalle]

Anything more I need to do?

[LilithHafner]

Nope! Thanks for the contribution :)

[nsajko]

@JeffBezanson requested that a branch with the buggy failing bootstrap be kept around, if I understood correctly. Is such a branch still available somewhere on Github?

[gdalle]

Yes, it's here: https://github.com/JuliaLang/julia/tree/b59efec2ab52690729e84bc2939310be499db4ad