absurdly slow operations on deeply nested pairs

[stevengj]

I noticed while testing #30471 that printing deeply nested Pair types seems absurdly slow. In Julia 1.0, I get:

julia> p = mapfoldl(abs, =>, -27:-1); @time println(p)
(((((((((((((((((((((((((27=>26)=>25)=>24)=>23)=>22)=>21)=>20)=>19)=>18)=>17)=>16)=>15)=>14)=>13)=>12)=>11)=>10)=>9)=>8)=>7)=>6)=>5)=>4)=>3)=>2) => 1
 48.127456 seconds (1.36 M allocations: 67.004 MiB, 0.04% gc time)

Almost a minute and over a million allocations to print a 150-character string doesn't seem right.

In contrast, mapfoldl(abs, Pair{Any,Any}, -50:-1) prints instantly, and similarly for calling println(p) a second time above, so the problem must have to do with compiling lots of code specialized for the different nested Pair types above.

It might be fixed by adding @nospecialize to the show function for Pair, but I wonder if there is a deeper problem & solution for nested parameterized types.

[ararslan]

I ran some profiling for this particular example. Here is the (very large) result of Profile.print(): https://gist.github.com/ararslan/20a69026b9ef57deaa34a4a5240474df

[KristofferC]

You can use the noisefloor argument to Profile.print to filter a bit.

[ararslan]

but I wonder if there is a deeper problem & solution for nested parameterized types.

Note that the same thing happens with tuples, e.g. if p is defined as mapfoldl(abs, (a,b)->(a,b), -27:-1), so that seems likely.

[ararslan]

For reference, on 0.6 I get

0.677295 seconds (722.29 k allocations: 36.904 MiB, 7.51% gc time)

and on 0.5

0.717157 seconds (1.09 M allocations: 45.945 MB, 12.60% gc time)

[rfourquet]

To confirm @ararslan 's comment that it doesn't happen only with Pair: the default printing for

struct P{K,V}
    a::K
    b::V
end

exhibits the same problem (and I get a timing even worst than for Pair, 50% slower)

[vtjnash]

fixed by b2b35e9 (#31680)