sort! return type not inferred properly

[sbromberger]

Git bisect results:

3b6221fa07505eac363028d46cb5120ed9bad629 is the first bad commit
commit 3b6221fa07505eac363028d46cb5120ed9bad629
Author: Kevin Squire <kevin@redacted>
Date:   Tue Jul 14 23:25:41 2015 -0700

    Update quicksort algorithms

    * Break out select_pivot!, partition!, functions
    * Share these among different quicksort variants
    * Switch select to use PartialQuickSort

:040000 040000 c8cdf04f0759540099ade72bb299e4b211839b08 b4ff52266f9fe20b7712b4cfdb54562a2251d9b2 M  base
:040000 040000 444b35b87c405e2118716139dab58c0fdf33a294 4cacea789ebbbcb1464fa2ed211c8fdd4dd6b18b M  doc

Yields the following difference:

Bad:

seth@schroeder:~/dev/julia/julia$ usr/bin/julia
               _
   _       _ _(_)_     |  A fresh approach to technical computing
  (_)     | (_) (_)    |  Documentation: http://docs.julialang.org
   _ _   _| |_  __ _   |  Type "help()" for help.
  | | | | | | |/ _` |  |
  | | |_| | | | (_| |  |  Version 0.4.0-dev+6206 (2015-07-24 17:38 UTC)
 _/ |\__'_|_|_|\__'_|  |  Commit 3b6221f (34 days old master)
|__/                   |  x86_64-apple-darwin14.5.0

julia> g = readgraph("/Users/seth/dev/julia/wip/LightGraphs.jl/test/testdata/pgp2.jgz")["pgp"]
{39796, 301498} directed graph

julia> h = g[1:3000]
{3000, 39576} directed graph

julia> j = DiGraph(10,20)
{10, 20} directed graph

julia> @time z = betweenness_centrality(j);  # compile
 264.387 milliseconds (323 k allocations: 14737 KB)

julia> @time z = betweenness_centrality(h);
  11.113 seconds      (171 M allocations: 4076 MB, 6.42% gc time)

Good:

seth@schroeder:~/dev/julia/julia$ usr/bin/julia
               _
   _       _ _(_)_     |  A fresh approach to technical computing
  (_)     | (_) (_)    |  Documentation: http://docs.julialang.org
   _ _   _| |_  __ _   |  Type "help()" for help.
  | | | | | | |/ _` |  |
  | | |_| | | | (_| |  |  Version 0.4.0-dev+6205 (2015-07-24 04:37 UTC)
 _/ |\__'_|_|_|\__'_|  |  Commit 7e8b3a9 (34 days old master)
|__/                   |  x86_64-apple-darwin14.5.0

julia> using LightGraphs

julia> g = readgraph("/Users/seth/dev/julia/wip/LightGraphs.jl/test/testdata/pgp2.jgz")["pgp"]
{39796, 301498} directed graph

julia> h = g[1:3000]
{3000, 39576} directed graph

julia> j = DiGraph(10,20)
{10, 20} directed graph

julia> @time z = betweenness_centrality(j);
 258.095 milliseconds (329 k allocations: 15039 KB)

julia> @time z = betweenness_centrality(j);
 143.090 microseconds (383 allocations: 29376 bytes)

julia> @time z = betweenness_centrality(h);
   2.741 seconds      (14265 k allocations: 1315 MB, 8.18% gc time)

Relevant code here: https://github.com/JuliaGraphs/LightGraphs.jl/blob/master/src/centrality/betweenness.jl#L99-L111

I believe this is caused by the call to sortperm().

[sbromberger]

cc @kmsquire

[kmsquire]

Looking into this...

[kmsquire]

It seems my sort changes introduced some type instability into sortperm (at least). If I change this line from

    S = sortperm(state.dists, rev=true)

to

    S = sortperm(state.dists, rev=true)::Vector{Int}

the performance regression goes away. Now I just need to figure out why that's happening.

[sbromberger]

Thank you for looking into this, @kmsquire!

[kmsquire]

Np. I don't like introducing performance regressions. ;-)

[kmsquire]

Progress: the rev keyword seems to be what introduces the type instability.

[kmsquire]

More progress: the PartialQuickSort type seems to be related to the instability. Or at least, if I temporarily remove that type, inference seems to work properly.

[kmsquire]

Simple way to reproduce the problem:

On master:

julia> Base.return_types(sort, (Vector{Int},))
1-element Array{Any,1}:
 Any

After fixing:

julia> Base.return_types(sort, (Vector{Int},))
1-element Array{Any,1}:
 Array{Int64,1}

Submitting a patch in a few minutes.

[kmsquire]

#12838

[sbromberger]

Again, many thanks for tracking this down. I'm looking forward to the merge. I'm also a bit puzzled as to why I was the first to find this (34 days after it happened). Is there no other performance-critical code using sortperm(rev=true)?

[sbromberger]

PS:

S = sortperm(state.dists, rev=true)::Vector{Int}

Fixes the regression, time-wise, but still results in massive overallocation:

julia> @time z = betweenness_centrality(h);
  2.938274 seconds (14.27 M allocations: 1.284 GB, 7.01% gc time)

[kmsquire]

What was the allocation previously (or with the merged patch)?

[kmsquire]

Nevermind, I see it above. What is it with the new patch?

[sbromberger]

The full log is in the initial message, but

julia> @time z = betweenness_centrality(h);
   2.741 seconds      (14265 k allocations: 1315 MB, 8.18% gc time)

So increases of 1000x allocations and 1000x memory. (yeah, units.)

[kmsquire]

Looks the same... (roughly)

[sbromberger]

Dunno - I'm still building the new version - the git bisect left me in a weird state so I had to do a make distcleanall.

[sbromberger]

New commit:

julia> @time z = betweenness_centrality(h);
  2.841934 seconds (14.27 M allocations: 1.284 GB, 7.85% gc time)

[sbromberger]

Let me try my proposed change to that commit and I'll let you know what comes up.

[sbromberger]

Nope, it didn't fix it:

julia> @time z = betweenness_centrality(h);
  2.734397 seconds (14.27 M allocations: 1.284 GB, 7.47% gc time)

[kmsquire]

I'm not sure that's something that needs fixing. The total amount of allocation that is happening isn't happening all at once--it's being allocated, released, and garbage collected throughout that call.

[KristofferC]

(As you of course know), excessive allocation usually mean that there is a type instability somewhere. Unless that is the case, why would the code suddenly allocate so much more?

[kmsquire]

But it doesn't allocate so much more. It's allocating about the same amount. (The printing of that allocation has gone through a few iterations, though...)

[sbromberger]

Oh, this is my mistake. Math units are HARD.

[KristofferC]

Oh, then forget what I said.

[kmsquire]

:-) No worries!

[KristofferC]

It's not like I was the last one who touched the printing of allocation numbers and sizes or something... *whistle.