[sage-devel] memory problem

['Martin R' via sage-devel]

Dear memory experts!

I am running a big, but simple computation and running out of memory, but
do not understand why. I am pretty sure that the problem is in the
computation of the moebius function. Below is a silly minimal example,
together with some checks to make sure it's in moebius_function.

I would like to know how to debug this. (I am also in need of a workaround)

Martin

sage: get_memory_usage()
5512.4296875
sage: for P in posets(7):
....: Q = P.with_bounds()
....: x=Q.moebius_function(Q.bottom(), Q.top())
....:
sage: get_memory_usage()
5517.24609375
sage: for P in posets(7):
....: Q = P.with_bounds()
....: x=Q.moebius_function(Q.bottom(), Q.top())
....:
sage: get_memory_usage()
5521.76953125
sage: reset()
sage: get_memory_usage()
5521.76953125
sage: for P in posets(7):
....: Q = P.with_bounds()
....:
sage: get_memory_usage()
5522.04296875
sage: for P in posets(7):
....: Q = P.with_bounds()
....:
sage: get_memory_usage()
5522.30078125
sage: for P in posets(7):
....: Q = P.with_bounds()
....: x = Q.bottom()
....:
sage: get_memory_usage()
5522.44140625

[Jori Mäntysalo]

I am running a big, but simple computation and running out of memory, but do
not understand why.  I am pretty sure that the problem is in the computation
of the moebius function.

moebius_function() uses _moebius_function_values, which means that the
result is implicitly cached.

['Martin R' via sage-devel]

Yes, but should't that be released once the poset is thrown away?

Post by 'Martin R' via sage-devel
I am running a big, but simple computation and running out of memory,

but do

Post by 'Martin R' via sage-devel
not understand why. I am pretty sure that the problem is in the

computation

Post by 'Martin R' via sage-devel
of the moebius function.

moebius_function() uses _moebius_function_values, which means that the
result is implicitly cached.
--
Jori MÀntysalo

[Nils Bruin]

Post by 'Martin R' via sage-devel
Yes, but should't that be released once the poset is thrown away?

import gc
from collections import Counter
gc.collect()

pre={id(c) for c in gc.get_objects()}
for P in posets(7):
Q = P.with_bounds()
x=Q.moebius_function(Q.bottom(), Q.top())
del P,Q,x
gc.collect()
gc.collect()
gc.collect()
post=Counter(type(o) for o in gc.get_objects() if id(o) not in pre)
sorted(post.iteritems(),key=lambda t: t[1])

doesn't particularly find much on the heap (especially not the second time
you run it), so if something leaks, then it's not python.

['Martin R' via sage-devel]

I still think that there is something odd going on. I do not understand
the following:

def check(n):
while True:
for P in Posets(n):
Q = P.with_bounds()
x = Q.moebius_function(Q.bottom(), Q.top())
print get_memory_usage()

##############################################
sage: check(4)
4257.41796875
4257.546875
4257.546875
4257.546875
4257.546875
^C---------------------------------------------------------------------------
KeyboardInterrupt Traceback (most recent call last)

sage: check(5)
4263.09375
4263.22265625
4263.22265625
4262.8515625
4262.8515625
4262.8515625
4262.8515625
^C---------------------------------------------------------------------------
KeyboardInterrupt Traceback (most recent call last)
sage: check(6)
4270.2421875
4271.515625
4271.515625
4271.515625
4271.64453125
4271.64453125
4271.64453125
4271.64453125
^C---------------------------------------------------------------------------
KeyboardInterrupt Traceback (most recent call last)
sage: check(7)
4293.3984375
4298.43359375
4302.9453125
4306.8125
4311.84765625
4316.875
4320.23046875
4325.26171875

[Jori Mäntysalo]

            Q = P.with_bounds()
            x = Q.moebius_function(Q.bottom(), Q.top())
        print get_memory_usage()

The code can be made a little shorter:

def check(n):
while True:
for P in Posets(n):
x = P._hasse_diagram.moebius_function(0, n-1)
print get_memory_usage()

It still has the same error limit, i.e. check(6) works but check(7) does
not. I played a little with the code, and gc.collect() does not seem to
make anything. After a little more I got

AttributeError: 'FinitePoset_with_category' object has no attribute '_hasse_diagram'

from the code!

I reset the notebook and tried

def check(n):
while True:
i = 0
for P in Posets(n):
x = P._hasse_diagram.moebius_function(0, n-1)
i += 1
if i > 2000:
break
print get_memory_usage()

and still get memory leak. But with i > 1000 it works. So it's not about
size of poset but the number of them.

Weird.

['Martin R' via sage-devel]

Thank you for looking into this. I think the problem exists also for the
following code, however only for n = 8:

def check_bad3(n):
from sage.graphs.digraph_generators import DiGraphGenerators
from sage.combinat.posets.hasse_diagram import HasseDiagram
for dig in DiGraphGenerators()(n, is_poset):
P = HasseDiagram(dig)
x = P.moebius_function(0, n-1)
print get_memory_usage()

[Jori Mäntysalo]

Thank you for looking into this.  I think the problem exists also for the

I did some other tests too, but only got confused. Hasse diagrams are just
graphs, I think -- they are not derived from UniqueRepresentation.

Can this be a bug in Python? Maybe we can make quick modification to
digraph code so that we can create posets with Py3-compiled Sage, and test
that. But all of this is above my knowledge. :=(

['Martin R' via sage-devel]

Can you confirm that running check_bad3 above allocates memory without
limits?

Martin

Post by Jori Mäntysalo

Post by 'Martin R' via sage-devel
Thank you for looking into this. I think the problem exists also for

the
I did some other tests too, but only got confused. Hasse diagrams are just
graphs, I think -- they are not derived from UniqueRepresentation.
Can this be a bug in Python? Maybe we can make quick modification to
digraph code so that we can create posets with Py3-compiled Sage, and test
that. But all of this is above my knowledge. :=(
--
Jori MÀntysalo

['Martin R' via sage-devel]

NEW MESSAGE:

I got it: breadth_first_search (used in HasseDiagram.is_lequal) leaks.

if I use breadth_first_search(i, distance=self.cardinality()) instead, the
leak is gone.

Martin


OLD MESSAGE:

I just tried with python3. The code runs. check_bad3(7) allocates roughly
0.5 megabytes per invocation. check_bad3(6) also steadily allocates, but
only about 0.1MB. check_bad3(5) even less.

So, in fact, in python3 they all leak memory, if that's what a memory leak
is.

And I made a mistake in my previous message. The same is true for python2,
but they leak much less memory. A few 100 runs are necessary so you see it
for check_bad3(4), for example.

However, as soon as I remove the call to moebius_function, the leak is gone.

Martin

[Jori Mäntysalo]

Post by 'Martin R' via sage-devel
Can you confirm that running check_bad3 above allocates memory without
limits?

Confirmed.

Post by 'Martin R' via sage-devel
I got it: breadth_first_search (used in HasseDiagram.is_lequal) leaks.
if I use breadth_first_search(i, distance=self.cardinality()) instead, the leak is gone.

That function starts with

# Preferably use the Cython implementation
if neighbors is None and . . . distance is None and . . .

so the problem must be in

for v in self._backend.breadth_first_search(start, ignore_direction=ignore_direction):
yield v

This goes to src/sage/graphs/base/c_graph.pyx cdef class Search_iterator,
which has

def __next__(self):
. . .
cdef bitset_t seen
. . .
def __init__
. . .
bitset_init(self.seen,
. . .
def __next__(self):
. . .
while self.stack:
. . .
break
else:
bitset_free(self.seen)
raise StopIteration

So, now when there is no reference to Search_iterator any more, should
Cython automatically clean up the space taken, or should there be an
explicit destructor?

['Martin R' via sage-devel]

I think it would be good to have a self-contained function that confirms
that breadth_first_search leaks.

It seems to me that the following does NOT leak.

def check_bad4(n):
from sage.graphs.digraph_generators import DiGraphGenerators
from sage.combinat.posets.hasse_diagram import HasseDiagram
for dig in DiGraphGenerators()(n, is_poset):
P = HasseDiagram(dig)
for i in range(n):
x = P.breadth_first_search(i)
print get_memory_usage()

Martin

[Jori Mäntysalo]

Post by 'Martin R' via sage-devel
It seems to me that the following does NOT leak.
        P = HasseDiagram(dig)
            x = P.breadth_first_search(i)

You don't stop the search in first match, so the memory will be freed. Try
addin break after P.breadth_first_search(i).

['Martin R' via sage-devel]

OK, here is code that certainly leaks and confirms what you found, Jori.
Congratulations!

def check_bad5(n):
"""

sage: check_bad5(100000)

"""
G = Graph(2)
for i in range(n):
x = 0 in G.breadth_first_search(0)
if i % 10000 == 0:
print get_memory_usage()

Martin

['Martin R' via sage-devel]

https://trac.sagemath.org/ticket/26794

Post by 'Martin R' via sage-devel
OK, here is code that certainly leaks and confirms what you found, Jori.
Congratulations!
"""
sage: check_bad5(100000)
"""
G = Graph(2)
x = 0 in G.breadth_first_search(0)
print get_memory_usage()
Martin

[Jori Mäntysalo]

Post by 'Martin R' via sage-devel
https://trac.sagemath.org/ticket/26794

I don't think that this is critical. The user never gets wrong answers
because of this.

Anyways, needs to be corrected. This is cython thing, not python. I'm not
familiar with cython, so maybe someone else should look at this. OTOH I
suppose this is an easy one, just add a destructor function (whatever it
is called in cython).

Harder one is to search for other similar bugs.

['Martin R' via sage-devel]

needs review.

[Nils Bruin]

Post by Jori Mäntysalo
x = P._hasse_diagram.moebius_function(0, n-1)
print get_memory_usage()
It still has the same error limit, i.e. check(6) works but check(7) does
not. I played a little with the code, and gc.collect() does not seem to
make anything. After a little more I got

I think this code most definitely leaks; also with n=6.

def check(n):
for j in [1..6]:
i = 0
for P in Posets(n):
x = P._hasse_diagram.moebius_function(0, n-1)
i += 1
if i > 2000:
break
print get_memory_usage()

import gc
from collections import Counter
gc.collect()

pre={id(c) for c in gc.get_objects()}
check(6)
gc.collect()
post=Counter(type(o) for o in gc.get_objects() if id(o) not in pre)
sorted(post.iteritems(),key=lambda t: t[1])

finds plenty of HasseDiagram objects on the heap.

You can look at backreference graphs, using "objgraph":

objgraph.show_backrefs([o for o in gc.get_objects() if type(o) is
sage.combinat.posets.hasse_diagram.HasseDiagram][5:6],max_depth=8,filename="graph.dot")

(you may have to experiment with the actual object you take the backrefs
of; not all of them are so well-connected)

You'll quickly see the object is in some "WeakCachedFunction" (a cached
__classcall__). The fact that the reference is found indicates the
HasseDiagram object is a key. Probably the value is something kept alive by
the key. The cache itself of course lives on a class, so has unlimited
lifespan. It will take a little bit more work to dig up the actual place
where the reference loop is made, but hopefully with this information
someone can find it.

I'm not sure this is the same memory problem the Martin originally stumbled
on, because there I was not seeing large numbers of objects on the heap.

[Nils Bruin]

Post by Nils Bruin
I'm not sure this is the same memory problem the Martin originally
stumbled on, because there I was not seeing large numbers of objects on the
heap.

Hm, I must have done the original test on a different version of sage. For
the original code, I'm seeing the same behaviour. So that means the
reference loop might have been introduced relatively recently.

['Martin R' via sage-devel]

I can make my observation now a bit more precise, and I am sure that there
is a memory problem.

I used

sage -pip install memory_profiler

Let memory.py be the following file:
###################################################
from memory_profiler import profile
@profile
def check_good(n):
for P in Posets(n):
Q = P.with_bounds()
print get_memory_usage()

@profile
def check_bad(n):
for P in Posets(n):
Q = P.with_bounds()
x = Q.moebius_function(Q.bottom(), Q.top())
print get_memory_usage()
##########################################################

The session below shows that no additional memory is allocated by
check_good and, for n<7 by check_bad(n). However, check_bad(7) allocates
additional memory on every run. Eventually, my computer runs out of memory
and the process is killed :-(

Help is very much appreciated!

Martin

┌────────────────────────────────────────────────────────────────────┐
│ SageMath version 8.5.beta4, Release Date: 2018-11-18 │
│ Using Python 2.7.15. Type "help()" for help. │
└────────────────────────────────────────────────────────────────────┘
┏━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┓
┃ Warning: this is a prerelease version, and it may be unstable. ┃
┗━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┛
sage: load('/home/martin/memory.py')
sage: %load_ext memory_profiler
sage: check_bad(3)
6216.8828125
Filename: /home/martin/memory.py

Line # Mem usage Increment Line Contents
================================================
21 210.5 MiB 210.5 MiB @profile
22 def check_bad(n):
23 227.0 MiB 2.9 MiB for P in Posets(n):
24 227.0 MiB 13.5 MiB Q = P.with_bounds()
25 227.0 MiB 0.0 MiB x =
Q.moebius_function(Q.bottom(), Q.top())
26 227.0 MiB 0.0 MiB print get_memory_usage()


sage: check_bad(3)
6217.1328125
Filename: /home/martin/memory.py

Line # Mem usage Increment Line Contents
================================================
21 227.2 MiB 227.2 MiB @profile
22 def check_bad(n):
23 227.2 MiB 0.0 MiB for P in Posets(n):
24 227.2 MiB 0.0 MiB Q = P.with_bounds()
25 227.2 MiB 0.0 MiB x =
Q.moebius_function(Q.bottom(), Q.top())
26 227.2 MiB 0.0 MiB print get_memory_usage()


sage: check_good(7)
6247.0390625
Filename: /home/martin/memory.py

Line # Mem usage Increment Line Contents
================================================
15 227.2 MiB 227.2 MiB @profile
16 def check_good(n):
17 256.9 MiB 18.8 MiB for P in Posets(n):
18 256.9 MiB 10.9 MiB Q = P.with_bounds()
19 256.9 MiB 0.0 MiB print get_memory_usage()


sage: check_good(7)
6247.296875
Filename: /home/martin/memory.py

Line # Mem usage Increment Line Contents
================================================
15 256.9 MiB 256.9 MiB @profile
16 def check_good(n):
17 257.2 MiB 0.3 MiB for P in Posets(n):
18 257.2 MiB 0.0 MiB Q = P.with_bounds()
19 257.2 MiB 0.0 MiB print get_memory_usage()


sage: check_bad(7)
6250.765625
Filename: /home/martin/memory.py

Line # Mem usage Increment Line Contents
================================================
21 257.4 MiB 257.4 MiB @profile
22 def check_bad(n):
23 260.5 MiB 2.6 MiB for P in Posets(n):
24 260.5 MiB 0.5 MiB Q = P.with_bounds()
25 260.5 MiB 0.0 MiB x =
Q.moebius_function(Q.bottom(), Q.top())
26 260.5 MiB 0.0 MiB print get_memory_usage()


sage: check_bad(7)
6255.66796875
Filename: /home/martin/memory.py

Line # Mem usage Increment Line Contents
================================================
21 260.5 MiB 260.5 MiB @profile
22 def check_bad(n):
23 265.4 MiB 3.4 MiB for P in Posets(n):
24 265.4 MiB 1.5 MiB Q = P.with_bounds()
25 265.4 MiB 0.0 MiB x =
Q.moebius_function(Q.bottom(), Q.top())
26 265.4 MiB 0.0 MiB print get_memory_usage()


sage: check_bad(7)
6258.890625
Filename: /home/martin/memory.py

Line # Mem usage Increment Line Contents
================================================
21 265.4 MiB 265.4 MiB @profile
22 def check_bad(n):
23 268.8 MiB 2.8 MiB for P in Posets(n):
24 268.8 MiB 0.5 MiB Q = P.with_bounds()
25 268.8 MiB 0.0 MiB x =
Q.moebius_function(Q.bottom(), Q.top())
26 268.8 MiB 0.0 MiB print get_memory_usage()