10-09-2024, 10:52 AM
(This post was last modified: 10-09-2024, 11:27 AM by willcattoneeca.)
Nice! You've made it a whole lot quicker!!
For me (Julia 1.9.4 but I don't think that is likely to cause any difference), running include("demo.jl") twice does still lead to the @time macro results reporting that Julia is spending a significant fraction of its time (for each of the small preliminary steps) on compilation. For instance, "54.38% compilation time" in the below output where I run it a second time. Do you see compilation time mentioned the second time you run include("demo.jl") in your REPL? Compilation is entirely eliminated the second time the "run_model" function gets executed in my fork.
The compilation time is a small part of the overall time at present, but it could seem significant e.g. if the goal is to get down to the 1 second ballpark. And since it can be eliminated it should be excluded from any estimate of the achievable performance.
(base) PS C:\Users\cattonw\git\TIMES.jl> julia --project=.
_
_ _ _(_)_ | Documentation: https://docs.julialang.org
(_) | (_) (_) |
_ _ _| |_ __ _ | Type "?" for help, "]?" for Pkg help.
| | | | | | |/ _` | |
| | |_| | | | (_| | | Version 1.9.4 (2023-11-14)
_/ |\__'_|_|_|\__'_| | Official https://julialang.org/ release
|__/ |
julia> include("demo.jl")
Define sets: 0.091661 seconds (106.66 k allocations: 7.145 MiB, 94.45% compilation time)
Load demo data (sets and parameters): 10.461156 seconds (17.31 M allocations: 1.128 GiB, 3.94% gc time, 81.63% compilation time)
Compute additional parameters: 0.321723 seconds (422.56 k allocations: 28.788 MiB, 4.00% gc time, 98.12% compilation time)
Compute additional sets: 3.165227 seconds (3.29 M allocations: 216.488 MiB, 2.12% gc time, 99.01% compilation time)
Create Variables: 4.322982 seconds (10.30 M allocations: 597.847 MiB, 4.41% gc time, 87.55% compilation time)
Objective Function: 0.423517 seconds (216.08 k allocations: 14.667 MiB, 3.00% gc time, 97.54% compilation time)
Specify constraints: 19.452738 seconds (97.60 M allocations: 5.401 GiB, 5.11% gc time, 63.17% compilation time)
Running HiGHS 1.7.2 (git hash: 5ce7a2753): Copyright © 2024 HiGHS under MIT licence terms
Coefficient ranges:
Matrix [1e-02, 1e+04]
Cost [1e+00, 1e+00]
Bound [1e-01, 1e+01]
RHS [9e-02, 8e+03]
Presolving model
265 rows, 285 cols, 963 nonzeros 0s
228 rows, 245 cols, 826 nonzeros 0s
Presolve : Reductions: rows 228(-376); columns 245(-4571); elements 826(-1094)
Solving the presolved LP
Using EKK dual simplex solver - serial
Iteration Objective Infeasibilities num(sum)
0 1.2861637975e+04 Pr: 30(74.9799) 0s
162 3.8706151237e+04 Pr: 0(0); Du: 0(1.35003e-13) 0s
Solving the original LP from the solution after postsolve
Model status : Optimal
Simplex iterations: 162
Objective value : 3.8706151237e+04
HiGHS run time : 0.02
Solve model: 0.228086 seconds (96.55 k allocations: 7.800 MiB, 76.42% compilation time: 33% of which was recompilation)
* Solver : HiGHS
* Status
Result count : 1
Termination status : OPTIMAL
Message from the solver:
"kHighsModelStatusOptimal"
* Candidate solution (result #1)
Primal status : FEASIBLE_POINT
Dual status : FEASIBLE_POINT
Objective value : 3.87062e+04
Objective bound : 0.00000e+00
Relative gap : Inf
Dual objective value : 3.87062e+04
* Work counters
Solve time (sec) : 2.07250e-02
Simplex iterations : 162
Barrier iterations : 0
Node count : -1
julia> include("demo.jl")
Define sets: 0.007051 seconds (1.63 k allocations: 106.188 KiB)
Load demo data (sets and parameters): 0.250902 seconds (123.93 k allocations: 6.411 MiB, 45.34% compilation time)
Compute additional parameters: 0.093254 seconds (32.46 k allocations: 2.268 MiB, 88.64% compilation time)
Compute additional sets: 2.109598 seconds (1.25 M allocations: 86.716 MiB, 1.60% gc time, 97.75% compilation time)
Create Variables: 2.623167 seconds (7.02 M allocations: 385.873 MiB, 4.27% gc time, 81.17% compilation time)
Objective Function: 0.027465 seconds (5.25 k allocations: 305.211 KiB, 64.73% compilation time)
Specify constraints: 15.146921 seconds (91.38 M allocations: 5.004 GiB, 5.57% gc time, 54.38% compilation time)
Running HiGHS 1.7.2 (git hash: 5ce7a2753): Copyright © 2024 HiGHS under MIT licence terms
Coefficient ranges:
Matrix [1e-02, 1e+04]
Cost [1e+00, 1e+00]
Bound [1e-01, 1e+01]
RHS [9e-02, 8e+03]
Presolving model
265 rows, 285 cols, 963 nonzeros 0s
228 rows, 245 cols, 826 nonzeros 0s
Presolve : Reductions: rows 228(-376); columns 245(-4571); elements 826(-1094)
Solving the presolved LP
Using EKK dual simplex solver - serial
Iteration Objective Infeasibilities num(sum)
0 1.2861637975e+04 Pr: 30(74.9799) 0s
162 3.8706151237e+04 Pr: 0(0); Du: 0(1.35003e-13) 0s
Solving the original LP from the solution after postsolve
Model status : Optimal
Simplex iterations: 162
Objective value : 3.8706151237e+04
HiGHS run time : 0.02
Solve model: 0.028188 seconds (35.32 k allocations: 3.690 MiB)
* Solver : HiGHS
* Status
Result count : 1
Termination status : OPTIMAL
Message from the solver:
"kHighsModelStatusOptimal"
* Candidate solution (result #1)
Primal status : FEASIBLE_POINT
Dual status : FEASIBLE_POINT
Objective value : 3.87062e+04
Objective bound : 0.00000e+00
Relative gap : Inf
Dual objective value : 3.87062e+04
* Work counters
Solve time (sec) : 1.58119e-02
Simplex iterations : 162
Barrier iterations : 0
Node count : -1
For me (Julia 1.9.4 but I don't think that is likely to cause any difference), running include("demo.jl") twice does still lead to the @time macro results reporting that Julia is spending a significant fraction of its time (for each of the small preliminary steps) on compilation. For instance, "54.38% compilation time" in the below output where I run it a second time. Do you see compilation time mentioned the second time you run include("demo.jl") in your REPL? Compilation is entirely eliminated the second time the "run_model" function gets executed in my fork.
The compilation time is a small part of the overall time at present, but it could seem significant e.g. if the goal is to get down to the 1 second ballpark. And since it can be eliminated it should be excluded from any estimate of the achievable performance.
(base) PS C:\Users\cattonw\git\TIMES.jl> julia --project=.
_
_ _ _(_)_ | Documentation: https://docs.julialang.org
(_) | (_) (_) |
_ _ _| |_ __ _ | Type "?" for help, "]?" for Pkg help.
| | | | | | |/ _` | |
| | |_| | | | (_| | | Version 1.9.4 (2023-11-14)
_/ |\__'_|_|_|\__'_| | Official https://julialang.org/ release
|__/ |
julia> include("demo.jl")
Define sets: 0.091661 seconds (106.66 k allocations: 7.145 MiB, 94.45% compilation time)
Load demo data (sets and parameters): 10.461156 seconds (17.31 M allocations: 1.128 GiB, 3.94% gc time, 81.63% compilation time)
Compute additional parameters: 0.321723 seconds (422.56 k allocations: 28.788 MiB, 4.00% gc time, 98.12% compilation time)
Compute additional sets: 3.165227 seconds (3.29 M allocations: 216.488 MiB, 2.12% gc time, 99.01% compilation time)
Create Variables: 4.322982 seconds (10.30 M allocations: 597.847 MiB, 4.41% gc time, 87.55% compilation time)
Objective Function: 0.423517 seconds (216.08 k allocations: 14.667 MiB, 3.00% gc time, 97.54% compilation time)
Specify constraints: 19.452738 seconds (97.60 M allocations: 5.401 GiB, 5.11% gc time, 63.17% compilation time)
Running HiGHS 1.7.2 (git hash: 5ce7a2753): Copyright © 2024 HiGHS under MIT licence terms
Coefficient ranges:
Matrix [1e-02, 1e+04]
Cost [1e+00, 1e+00]
Bound [1e-01, 1e+01]
RHS [9e-02, 8e+03]
Presolving model
265 rows, 285 cols, 963 nonzeros 0s
228 rows, 245 cols, 826 nonzeros 0s
Presolve : Reductions: rows 228(-376); columns 245(-4571); elements 826(-1094)
Solving the presolved LP
Using EKK dual simplex solver - serial
Iteration Objective Infeasibilities num(sum)
0 1.2861637975e+04 Pr: 30(74.9799) 0s
162 3.8706151237e+04 Pr: 0(0); Du: 0(1.35003e-13) 0s
Solving the original LP from the solution after postsolve
Model status : Optimal
Simplex iterations: 162
Objective value : 3.8706151237e+04
HiGHS run time : 0.02
Solve model: 0.228086 seconds (96.55 k allocations: 7.800 MiB, 76.42% compilation time: 33% of which was recompilation)
* Solver : HiGHS
* Status
Result count : 1
Termination status : OPTIMAL
Message from the solver:
"kHighsModelStatusOptimal"
* Candidate solution (result #1)
Primal status : FEASIBLE_POINT
Dual status : FEASIBLE_POINT
Objective value : 3.87062e+04
Objective bound : 0.00000e+00
Relative gap : Inf
Dual objective value : 3.87062e+04
* Work counters
Solve time (sec) : 2.07250e-02
Simplex iterations : 162
Barrier iterations : 0
Node count : -1
julia> include("demo.jl")
Define sets: 0.007051 seconds (1.63 k allocations: 106.188 KiB)
Load demo data (sets and parameters): 0.250902 seconds (123.93 k allocations: 6.411 MiB, 45.34% compilation time)
Compute additional parameters: 0.093254 seconds (32.46 k allocations: 2.268 MiB, 88.64% compilation time)
Compute additional sets: 2.109598 seconds (1.25 M allocations: 86.716 MiB, 1.60% gc time, 97.75% compilation time)
Create Variables: 2.623167 seconds (7.02 M allocations: 385.873 MiB, 4.27% gc time, 81.17% compilation time)
Objective Function: 0.027465 seconds (5.25 k allocations: 305.211 KiB, 64.73% compilation time)
Specify constraints: 15.146921 seconds (91.38 M allocations: 5.004 GiB, 5.57% gc time, 54.38% compilation time)
Running HiGHS 1.7.2 (git hash: 5ce7a2753): Copyright © 2024 HiGHS under MIT licence terms
Coefficient ranges:
Matrix [1e-02, 1e+04]
Cost [1e+00, 1e+00]
Bound [1e-01, 1e+01]
RHS [9e-02, 8e+03]
Presolving model
265 rows, 285 cols, 963 nonzeros 0s
228 rows, 245 cols, 826 nonzeros 0s
Presolve : Reductions: rows 228(-376); columns 245(-4571); elements 826(-1094)
Solving the presolved LP
Using EKK dual simplex solver - serial
Iteration Objective Infeasibilities num(sum)
0 1.2861637975e+04 Pr: 30(74.9799) 0s
162 3.8706151237e+04 Pr: 0(0); Du: 0(1.35003e-13) 0s
Solving the original LP from the solution after postsolve
Model status : Optimal
Simplex iterations: 162
Objective value : 3.8706151237e+04
HiGHS run time : 0.02
Solve model: 0.028188 seconds (35.32 k allocations: 3.690 MiB)
* Solver : HiGHS
* Status
Result count : 1
Termination status : OPTIMAL
Message from the solver:
"kHighsModelStatusOptimal"
* Candidate solution (result #1)
Primal status : FEASIBLE_POINT
Dual status : FEASIBLE_POINT
Objective value : 3.87062e+04
Objective bound : 0.00000e+00
Relative gap : Inf
Dual objective value : 3.87062e+04
* Work counters
Solve time (sec) : 1.58119e-02
Simplex iterations : 162
Barrier iterations : 0
Node count : -1