fpylll really slow in sage9.x, when compared to sage8.x

[Julian Nowakowski]

Hi all,

we recently noticed that the IntegerMatrix class from fpylll is (on our hardware) much slower in sage9.x, than it is in sage8.x.

Please consider the following code snippet:

import time
from fpylll import IntegerMatrix

dim = 30
bits = 10

A = IntegerMatrix.random( dim, "uniform", bits = bits )
B = IntegerMatrix.random( dim, "uniform", bits = bits )

start = time.time()
C = A*B
stop = time.time()

print( "Multiplication took %f seconds." % (stop-start) )

We tried running this code in Sage 8.1, 8.9, 9.3 and 9.7. In the 8.x versions, the multiplications takes less than 0.2 seconds. In the 9.x versions, it takes more than 6 seconds.

Any ideas?

Best,

Julian

--

https://juliannowakow.ski/

[Martin R. Albrecht]

Hi there,

I don’t think A*B is a good benchmark for FPyLLL does the same slowdown also appear for, say, LLL?

Cheers,
Martin

--

_pgp: https://keybase.io/martinralbrecht
_www: https://malb.io
_prn: he/him or they/them

[Julian Nowakowski]

Hi Martin,

the slowdown also appears in other contexts. In particular, it also appears when running LLL.

Running the following code on our machine takes approximately 1 second with sage 8.1 and 8.9, but approximately 10 seconds with sage 9.3 and 9.7.

import time
from fpylll import IntegerMatrix, LLL

dim = 250
bits = 3

A = IntegerMatrix.random( dim, "uniform", bits = bits )

start = time.time()
LLL.reduction(A)
stop = time.time()

print("LLL took %f seconds." % (stop-start))

Best,

Julian

[Dima Pasechnik]

This does not appear to be Sage-related.
You can run the code above in Python shell.
(e.g. you can start Sage's python as "sage --python")

HTH
Dima

> --
> You received this message because you are subscribed to the Google Groups "sage-devel" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to sage-devel+...@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/msgid/sage-devel/73f9e6ea-cdc4-4d43-a2fc-abbfa144d71cn%40googlegroups.com.

[Julian Nowakowski]

Hi Dima,

thank you for your suggestion.

We still think that this issue is Sage-related.

We have already tried to figure out, whether the slowdown is simply an issue of fpylll.

If that was the case, then the slowdown would probably be caused by one of the following two issues:

1) The newer versions of fpylll, that ship with sage9, might be much slower than the older versions, that ship with sage8.

2) Running fpylll with python2 (as in sage8) might be much faster than running it with python3 (as in sage9).

To test, if that is case, we built the versions of fpylll, that ship with sage9, by ourselves.

We then ran the above code in these builds, using both python2 and python3.

In these runs, fpylll was just as fast as it was in sage8.x.

So the slowdown is probably not caused by the differences in fpylll/python versions.

It seems more likely to us that sage 9.x is doing something strange when building fpylll and that this is causing the slowdown.

Best,

Julian

[Dima Pasechnik]

On Wed, Jan 11, 2023 at 2:02 PM 'Julian Nowakowski' via sage-devel
<sage-...@googlegroups.com> wrote:
>
> Hi Dima,
>
> thank you for your suggestion.
>
> We still think that this issue is Sage-related.
> We have already tried to figure out, whether the slowdown is simply an issue of fpylll.
> If that was the case, then the slowdown would probably be caused by one of the following two issues:
>
> 1) The newer versions of fpylll, that ship with sage9, might be much slower than the older versions, that ship with sage8.
> 2) Running fpylll with python2 (as in sage8) might be much faster than running it with python3 (as in sage9).
>
> To test, if that is case, we built the versions of fpylll, that ship with sage9, by ourselves.
> We then ran the above code in these builds, using both python2 and python3.
> In these runs, fpylll was just as fast as it was in sage8.x.
> So the slowdown is probably not caused by the differences in fpylll/python versions.
>
> It seems more likely to us that sage 9.x is doing something strange when building fpylll and that this is causing the slowdown.

Are you using a binary distribution of Sage? We are not maintaining
any, so that's then
the question for maintainers of such a binary then.

Then, I don't think fpylll matters here, for it's just a thin wrapper
for libfplll, written in C++, and the
LLL computations is done there, not in Python.

It might be that you are using a slow libfplll, e.g. installed by your
package manager -
then it's likely a binary which does not use full capacities of your CPU,
whereas older versions of Sage have been building libfplll from source.


Without more details on your platform, it's hard to tell what exactly
goes wrong.

> To view this discussion on the web visit https://groups.google.com/d/msgid/sage-devel/d0abe8fb-d821-48b1-8aee-aa10a61754b4n%40googlegroups.com.

[Carl Richard Theodor Schneider]

Hi all,

I am one of the persons Julian meant with “we”, thus able to clarify a bit about the setup:

On our servers, where we noticed the problem first, we are running Ubuntu with sagemath installed from their official repos. One server still had sage 8.1 available, which is where we noticed the discrepancy.

But I was also able to reproduce this performance regression on my laptop, which runs NixOS. I built both sage 8.9 and sage 9.6 locally (including dependencies, in this case down to fplll) and was able to verify that the issue exists there, too.

Additionally, I tried the recommendation from Dima, running the code with `sage --python`, and also used fpylll directly from python2 and python3 (as the demo code does not use anything besides fpylll).

The running time using python3 (using the same fpylll and fplll dependencies as sage) was the expected short runtime, while sage took an order of magnitude more time.

I think using the same fpylll/fplll files on the file system should rule out any slow libfplll instance, as it works fine with direct python3 usage, while it is slow when used from within sage.

I have attached the code I used (flake.nix) to reproduce this behavior on my laptop, as well as the output (sage-fpylll.log) when run on my laptop. I assume that not everyone wants to run the code by themselves, due to it requiring to compile two sage versions.

In the log, the most interesting lines are 40/47 showing the time for sage (>7s) versus line 53 showing the time for py3 (~0.5s), using the same fplll dependency as shown from line 55 onwards.

Best Regards,

Richard

[Dima Pasechnik]

First of all, you're really on your own as far as Python2 is concerned.
We've moved on, there is no reason to use it on anything but
unupgradable old software.

It's not clear from your message whether you saw any difference from
python3 vs "sage --python".
Could you clarify?

Could you please also say what versions of libfplll you were trying.


Dima

On Wed, Jan 11, 2023 at 4:16 PM 'Carl Richard Theodor Schneider' via

> To view this discussion on the web visit https://groups.google.com/d/msgid/sage-devel/0d12f15d-21ff-4d39-a2dc-1df1dd5a1684n%40googlegroups.com.

[Nils Bruin]

Of course going back to py2 is not a solution but the data point is indicative that a regression was introduced, and that would be worth solving. It looks to me the following code is what exhibits the problematic behaviour. Run on a recent sage (9.7 or so):

sage: from fpylll import *

sage: FPLLL.set_random_seed(0)
sage: dim = 250
....: bits = 3
....: A = IntegerMatrix.random(dim, "uniform", bits = bits)
sage: %prun B = LLL.reduction(A)

(with profiling to see if anything comes to light):

         19250003 function calls (18500003 primitive calls) in 6.983 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
   125000    0.665    0.000    3.127    0.000 <frozen importlib._bootstrap>:921(_find_spec)
375000/125000    0.612    0.000    6.368    0.000 <frozen importlib._bootstrap>:1022(_find_and_load)
        1    0.548    0.548    6.983    6.983 <string>:1(<module>)
   125000    0.504    0.000    1.525    0.000 <frozen importlib._bootstrap_external>:1536(find_spec)
   375000    0.389    0.000    0.719    0.000 <frozen importlib._bootstrap>:179(_get_module_lock)
375000/125000    0.326    0.000    5.472    0.000 <frozen importlib._bootstrap>:987(_find_and_load_unlocked)
   625000    0.268    0.000    0.668    0.000 <frozen importlib._bootstrap_external>:126(_path_join)
   375000    0.264    0.000    0.328    0.000 <frozen importlib._bootstrap>:125(release)
   375000    0.261    0.000    0.325    0.000 <frozen importlib._bootstrap>:100(acquire)
   625000    0.249    0.000    0.331    0.000 <frozen importlib._bootstrap_external>:128(<listcomp>)
   375000    0.206    0.000    0.273    0.000 <frozen importlib._bootstrap>:71(__init__)
   125000    0.200    0.000    0.200    0.000 {built-in method posix.stat}

...........
 

Nevermind that the times don't add up, we see a profile that is completely dominated by import stuff! So it looks to me we may have ended up with an import in some fairly tight loop. Regardless of whether this is the actual source of the problem observed here, I think it's problematic in its own right.

[Martin R. Albrecht]

Thanks, it’s this function and a similar one the other way, i.e. an FPyLLL issue when used inside Sage:

```
cdef int assign_mpz(mpz_t& t, value) except -1:
"""
Assign Python integer to Z_NR[mpz_t]
"""
if isinstance(value, int) and PY_MAJOR_VERSION == 2:
mpz_set_si(t, PyInt_AS_LONG(value))
return 0
if isinstance(value, long):
mpz_set_pylong(t, value)
return 0
if have_sage:
from sage.rings.integer import Integer
if isinstance(value, Integer):
value = long(value)
mpz_set_pylong(t, value)
return 0
```

Per your profiler output we’re calling this 2*250*250 times, i.e. once to convert in and once to convert out.

This should be fixed with this PR:

https://github.com/fplll/fpylll/pull/239

I’ll cut a new release and update https://trac.sagemath.org/ticket/34870

Cheers,
Martin

[Carl Richard Theodor Schneider]

> First of all, you're really on your own as far as Python2 is concerned.

Yes, I know and understand this. The intention behind this was merely to provide another data point, as Nils noticed.

> It's not clear from your message whether you saw any difference from

> python3 vs "sage --python".
> Could you clarify?

The time for both `sage` and `sage --python` was >7s for both in the sage 9.x-case, while the native usage of fpylll from within python3 ran in the expected time (same order of magnitude as sage8.x and py2). The three test cases for the recent version are in line 35-40, 42-47 and 49-53 of the log.

> Could you please also say what versions of libfplll you were trying.

In the case where everything worked fine, the versions are:

sage: SageMath version 8.9, Release Date: 2019-09-29
py: 2.7.18 (default, Apr 19 2020, 21:45:35)     [GCC 9.3.0]
fpylll: 0.5.1dev
fplll: 5.3.2

In the case where sage was slow, but py3 performed as expected, the code ran with these versions:

sage: SageMath version 9.6, Release Date: 2022-05-15
py: 3.10.5 (main, Jun  6 2022, 12:05:50) [GCC 11.3.0]
fpylll: 0.5.7
fplll: 5.4.2

I'll apply the patch from the PR to verify whether it resolves the problem and report back (probably in the afternoon for UTC+1).

Best Regards and thanks for the help so far,

Richard

[Carl Richard Theodor Schneider]

I can confirm that the PR fixes this performance regression. I have provided more details in a comment on the PR.

Thanks again for the quick resolution.

Best Regards,

Richard