QuadFormAndIsom sometimes needing absurd time in CI

[lgoettgens]

Describe the bug
The file experimental/QuadFormAndIsom/test/runtest.jl needs almost an hour if CI time.
See https://github.com/oscar-system/Oscar.jl/actions/runs/5683498908/job/15404205914?pr=2598#step:6:1165 (nightly, macOS) and https://github.com/oscar-system/Oscar.jl/actions/runs/5682985233/job/15402594964#step:6:1165 (nightly, macOS).

To Reproduce
No idea. Once I find more logs, I add them here to hopefully get some idea. Ubuntu nightly jobs most times don't even get to this test due to #2441.

Cc @StevellM

[thofma]

I had hoped that this would be #2543, but this does not seem to be the case?

[lgoettgens]

JuliaLang/julia#50599 (which should have fixed #2543, we just cannot check this as there are other errors occurring earlier in ci) has been merged a few days ago and the logs above are from yesterday. So unfortunately this seems to be something different.

[benlorenz]

page: ~/work/Oscar.jl/Oscar.jl/experimental/QuadFormAndIsom/src/enumeration.jl:728-758
Error: Process completed with exit code 143.

The corresponding doctest also seems quite demanding regarding memory:

julia> L = root_lattice(:E,7);

julia> f = matrix(QQ, 7, 7, [ 1  1  2  1  0  0  1;
                              -1 -2 -3 -2 -1 -1 -1;
                               0  1  2  1  1  1  1;
                               0  0 -1 -1 -1 -1 -1;
                               1  1  2  2  2  1  1;
                               0  0 -1 -1 -1  0  0;
                               0  0  0  1  0  0  0]);

julia> Lf = integer_lattice_with_isometry(L, f)
Integer lattice of rank 7 and degree 7
  with isometry of finite order 6
  given by
  [ 1    1    2    1    0    0    1]
  [-1   -2   -3   -2   -1   -1   -1]
  [ 0    1    2    1    1    1    1]
  [ 0    0   -1   -1   -1   -1   -1]
  [ 1    1    2    2    2    1    1]
  [ 0    0   -1   -1   -1    0    0]
  [ 0    0    0    1    0    0    0]

julia> @time @eval reps = splitting_of_mixed_prime_power(Lf, 2)
167.263200 seconds (217.09 M allocations: 13.930 GiB, 5.83% gc time, 95.10% compilation time: <1% of which was recompilation)
2-element Vector{ZZLatWithIsom}:
 Integer lattice with isometry of finite order 12
 Integer lattice with isometry of finite order 12

On my laptop the memory usage when running just this block goes up to 4.5GB, but this seems to be during compilation and not running the code.

Repeating the code gives:

julia> @time @eval reps = splitting_of_mixed_prime_power(Lf, 2)
  7.496704 seconds (9.87 M allocations: 522.507 MiB, 84.75% gc time, 0.00% compilation time)

[thofma]

@benlorenz I see a slightly larger memory usage on julia nightly than on julia 1.9 for this example from the doctst. Not sure this explains the observation in OP.

[fingolfin]

Running JET's @report_opt on the splitting_of_mixed_prime_power call reports a gazillion things that could be improved. There is a lot of runtime dispatch going one, despite all that time being spent on compilation.

I also took a look with the memory profiler, and over 50% of the allocation in the splitting_of_mixed_prime_power above (of which there are ~8.4 million, depending on the initial seed) come from type inference caused by type unstable code (the kind of issue that JET helps tracking down).

About 10% of the allocations are of type Vector{Any} which does not bode well. Another 10% are ZZRingElem; that might (or might not) suggest some code should be adapted to use in-place operations (like add!, mul!, etc.).

I am going to dig a bit more to see if I can report something that's actually helpful...

[simonbrandhorst]

@StevellM is this resolved?