SQP Timer

[Foggalong]

Starting to address #16, adding a time limit for the SQP across all iterations rather than just each individual iteration.

[Foggalong]

This seems to be working for Gurobi, but for some reason HiGHS often thinks it has run out of time when it hasn't. I initially encountered this with the $n = 1,000$ problem but have been able to replicate it with any example where the time limit is set just above what HiGHS normally takes.

For example, solving the $n = 4$ problem with a time limit of 0.003 (with some added debug logs like

print(f"{100*(time_limit-time_remaining)/time_limit:.1f}% of time "
      f"used, {time_remaining:.6f} seconds left")

) gives

s1985194@migs:~/Work/rocs/module$ ./timing-sqp.sh 
Testing rocs.gurobi_robust_genetics_sqp(sigma, mubar, omega, sires, dams, lam, kap, n, time_limit=T)
Set parameter Username
Academic license - for non-commercial use only - expires 2025-02-26
21.84% seconds used
34.51% seconds used
41.60% seconds used
48.94% seconds used
56.24% seconds used
64.71% seconds used
72.28% seconds used
83.25% seconds used
98.78% seconds used
100.81% seconds used
Traceback (most recent call last):
  File "/usr/lib/python3.10/timeit.py", line 335, in main
    raw_timings = t.repeat(repeat, number)
  File "/usr/lib/python3.10/timeit.py", line 206, in repeat
    t = self.timeit(number)
  File "/usr/lib/python3.10/timeit.py", line 178, in timeit
    timing = self.inner(it, self.timer)
  File "<timeit-src>", line 23, in inner
    rocs.gurobi_robust_genetics_sqp(sigma, mubar, omega, sires, dams, lam, kap, n, time_limit=T)
  File "/home/s1985194/Work/rocs/module/./robustocs/solvers.py", line 440, in gurobi_robust_genetics_sqp
    raise RuntimeError("Gurobi hit time limit without optimality")
RuntimeError: Gurobi hit time limit without optimality

Testing rocs.highs_robust_genetics_sqp(sigma, mubar, omega, sires, dams, lam, kap, n, time_limit=T)
Running HiGHS 1.7.2 (git hash: 184e327): Copyright (c) 2024 HiGHS under MIT licence terms
20.81%, 0.0006244182586669922 seconds used
30.56%, 0.0009167194366455078 seconds used
40.25%, 0.0012073516845703125 seconds used
50.17%, 0.001505136489868164 seconds used
59.20%, 0.001775979995727539 seconds used
Traceback (most recent call last):
  File "/usr/lib/python3.10/timeit.py", line 335, in main
    raw_timings = t.repeat(repeat, number)
  File "/usr/lib/python3.10/timeit.py", line 206, in repeat
    t = self.timeit(number)
  File "/usr/lib/python3.10/timeit.py", line 178, in timeit
    timing = self.inner(it, self.timer)
  File "<timeit-src>", line 23, in inner
    rocs.highs_robust_genetics_sqp(sigma, mubar, omega, sires, dams, lam, kap, n, time_limit=T)
  File "/home/s1985194/Work/rocs/module/./robustocs/solvers.py", line 825, in highs_robust_genetics_sqp
    raise RuntimeError(f"HiGHS did not achieve optimality at "
RuntimeError: HiGHS did not achieve optimality at approximation #4, status HighsModelStatus.kTimeLimit

with HiGHS deciding to stop when it still has ~30% of it's time left.

If I comment out these three lines though then HiGHS runs to completion

Testing rocs.gurobi_robust_genetics_sqp(sigma, mubar, omega, sires, dams, lam, kap, n, time_limit=T)
Set parameter Username
Academic license - for non-commercial use only - expires 2025-02-26
20.83% 0.00237510 seconds left
33.20% 0.00200413 seconds left
39.66% 0.00181005 seconds left
45.33% 0.00164006 seconds left
53.30% 0.00140093 seconds left
64.57% 0.00106285 seconds left
72.30% 0.00083087 seconds left
82.41% 0.00052784 seconds left
96.67% 0.00009988 seconds left
101.44% -0.00004317 seconds left
Traceback (most recent call last):
  File "/usr/lib/python3.10/timeit.py", line 335, in main
    raw_timings = t.repeat(repeat, number)
  File "/usr/lib/python3.10/timeit.py", line 206, in repeat
    t = self.timeit(number)
  File "/usr/lib/python3.10/timeit.py", line 178, in timeit
    timing = self.inner(it, self.timer)
  File "<timeit-src>", line 23, in inner
    rocs.gurobi_robust_genetics_sqp(sigma, mubar, omega, sires, dams, lam, kap, n, time_limit=T)
  File "/home/s1985194/Work/rocs/module/./robustocs/solvers.py", line 439, in gurobi_robust_genetics_sqp
    raise RuntimeError(f"Gurobi hit time limit of {time_limit} "
RuntimeError: Gurobi hit time limit of 0.003 seconds without reaching optimality

Testing rocs.highs_robust_genetics_sqp(sigma, mubar, omega, sires, dams, lam, kap, n, time_limit=T)
Running HiGHS 1.7.2 (git hash: 184e327): Copyright (c) 2024 HiGHS under MIT licence terms
20.42% 0.00238726 seconds left
29.10% 0.00212691 seconds left
37.70% 0.00186894 seconds left
46.57% 0.00160287 seconds left
55.29% 0.00134132 seconds left
63.48% 0.00109551 seconds left
(array([0.5, 0.5, 0. , 0. ]), 0.23570226039551467, 0.6392977396044853)
raw times: 0.00373 sec

1 loop, best of 1: 0.00373 sec per loop

but weirdly produces something which isn't the true robust solution.

So far I've checked that the time limit is being set in HiGHS correctly and that it's not doing some weird rounding, but both are happening correctly. More testing needed.

[Foggalong]

Within SQP, it won't be possible to restrict HiGHS to use at most the remaining unused time. On initiating HiGHS with highspy.Highs() it starts an internal clock. Setting the time_limit option value puts a restriction on how long that internal clock has been running, not against how long HiGHS has to do a specific action. With the C/C++ API it's possible to work around that using zeroAllClocks, but that method is explicitly not included for the Python API.

This is intended behaviour, but not accounting for it caused the above issue; even though the time to solve was not fully used up, to HiGHS the remaining time was already used through other non-solve actions (e.g. model building). Gurobi on the other hand only counts solver time, hence the disparity. HiGHS may change its default behaviour in 2.0 to restrict solver time only, but until then

h.setOptionValue('time_limit', time_remaining)

will be commented out and ROCS will track the used solver time manually with time().

A side effect is that (mid-SQP) it is not possible to tell HiGHS directly that it only has $T$ time for a specific h.run(). This could be done indirectly by introducing threads or signals, but those are both more heavy duty than feels appropriate to introduce for this. This does mean though that HiGHS will overrun its time limit when reached mid-iteration.