Poor Initial Model Solve Time

[pulsipher]

I am revisiting the performance results I shared in #108 and I have found that the time to translate the initial model with POI to the solver now scales quite poorly relative to JuMP (I don't recall having this problem before after #114 when I tried last year).

using JuMP, Gurobi, ParametricOptInterface
const POI = ParametricOptInterface

function create_model(n, use_param)
    # Initialize the model object
    if use_param
        model = Model(() -> POI.Optimizer(Gurobi.Optimizer(), evaluate_duals = false))
        @variable(model, Mp in POI.Parameter(2.0))
    else
        model = Model(Gurobi.Optimizer)
        Mp = 2.0
    end

    set_silent(model)
    set_time_limit_sec(model, 0) # We want to include how long it takes to reach the solver, but that's it.

    # Add the variables
    @variable(model, d)
    @variable(model, 0 ≤ y[1:n, 1:2] ≤ 1)
    @variable(model, z[0:n, 0:n, 1:n], Bin)
    @variable(model, 0 ≤ s[0:n, 0:n, 1:n])
    @variable(model, r[0:n, 0:n, 1:n, 1:2])
    
    # Set the objective
    @objective(model, Min, d)
    
    # Add the constraints
    @constraint(model, [i ∈ 0:n, j ∈ 0:n], sum(z[i,j,f] for f ∈ 1:n) == 1)
    @constraint(model, [i ∈ 0:n, j ∈ 0:n, f ∈ 1:n], s[i,j,f] == d + Mp*(1 - z[i,j,f]))
    @constraint(model, [i ∈ 0:n, j ∈ 0:n, f ∈ 1:n], r[i,j,f,1] == i/n - y[f,1])
    @constraint(model, [i ∈ 0:n, j ∈ 0:n, f ∈ 1:n], r[i,j,f,2] == j/n - y[f,2])
    @constraint(model, [i ∈ 0:n, j ∈ 0:n, f ∈ 1:n], r[i,j,f,1]^2 + r[i,j,f,2]^2 ≤ s[i,j,f]^2)

    # Return the model
    return model
end

# Set test settings
n = 10 # This can vary the problem size

# Account for the jit time 
optimize!(create_model(2, true))
optimize!(create_model(2, false))

# Time with POI
@time optimize!(create_model(n, true))

# Time without POI
@time optimize!(create_model(n, false))

With n=10 using POI v0.4.3, JuMP v1.9, and Gurobi v1.0 I get:

0.075508 seconds (529.07 k allocations: 28.067 MiB) # POI
0.056373 seconds (405.03 k allocations: 23.210 MiB, 32.37% gc time, 17.23% compilation time) # JuMP

With n = 20 I get:

2.823058 seconds (3.84 M allocations: 198.879 MiB, 1.44% gc time) # POI (factor of 37 increase)
0.186521 seconds (2.78 M allocations: 155.695 MiB, 23.99% gc time) # JuMP (factor of 3 increase)

With n = 30 I get:

34.339958 seconds (12.53 M allocations: 646.085 MiB, 1.24% gc time) # POI (factor of 12 increase)
0.685356 seconds (9.04 M allocations: 505.112 MiB, 27.98% gc time) # JuMP (factor of 4 increase)

With n = 40 I get:

283.982509 seconds (29.20 M allocations: 1.475 GiB, 0.29% gc time) # POI (factor of 8 increase)
2.037777 seconds (21.06 M allocations: 1.148 GiB, 35.14% gc time) # JuMP (factor of 3 increase)

For my tests, this poor scalability in the initial build/solve time negates the benefit from faster resolve builds.

[joaquimg]

@pulsipher we tested locally (with version 0.5.0) and got:

n = 10
With POI
  0.044798 seconds (294.44 k allocations: 24.596 MiB)
Without POI
  0.034291 seconds (229.99 k allocations: 18.008 MiB)
n = 20
With POI
  0.363822 seconds (2.12 M allocations: 173.889 MiB, 21.93% gc time)
Without POI
  0.356139 seconds (1.65 M allocations: 126.521 MiB, 26.95% gc time)
n = 30
With POI
  1.509753 seconds (6.92 M allocations: 564.264 MiB, 32.25% gc time)
Without POI
  1.193309 seconds (5.39 M allocations: 410.021 MiB, 31.71% gc time)
n = 40
With POI
  3.311930 seconds (16.11 M allocations: 1.286 GiB, 26.13% gc time)
Without POI
  2.581702 seconds (12.55 M allocations: 954.376 MiB, 21.15% gc time)
n = 50
With POI
  6.229631 seconds (31.16 M allocations: 2.443 GiB, 22.18% gc time)
Without POI
  4.974451 seconds (24.26 M allocations: 1.793 GiB, 21.89% gc time)

can you re-run your tests?

[pulsipher]

Good work on the refactoring! I can confirm the issue is now resolved. I get the following:

n = 10
With POI
  0.055789 seconds (511.25 k allocations: 29.792 MiB)
Without POI
  0.051452 seconds (382.75 k allocations: 21.984 MiB)

n = 20
With POI
  0.685148 seconds (3.71 M allocations: 211.965 MiB, 59.93% gc time)
Without POI
  0.270249 seconds (2.78 M allocations: 155.694 MiB, 13.96% gc time)

n = 30
With POI
  1.125412 seconds (12.10 M allocations: 688.445 MiB, 21.65% gc time)
Without POI
  0.957738 seconds (9.04 M allocations: 505.112 MiB, 32.97% gc time)

n = 40
With POI
  3.047981 seconds (28.20 M allocations: 1.568 GiB, 26.29% gc time)
Without POI
  2.118862 seconds (21.06 M allocations: 1.148 GiB, 29.27% gc time)

n = 50
With POI
  5.506121 seconds (54.73 M allocations: 2.994 GiB, 25.72% gc time)
Without POI
  4.106402 seconds (40.93 M allocations: 2.215 GiB, 26.09% gc time)

[joaquimg]

Awesome!
Let us know if there are any other future issues.
PS. we intend to improve even more the efficiency, if possible.