Leaks in newform.pyx/mwrank.pyx/wrap.cc in Sage 3.2.x

[mabshoff]

Hello folks,

while chasing a leak you could drive a truck through in sparse linear
matrix multiplication I also poked around the logs for issues in
mwrank and eclib since when testing the point counting code John did
mention some problems with RAM being eaten up. Below are issues from
three different files. None of those has tickets yet, but if anybody
wants to look into this I can open them. I myself won't have time to
work on this probably for a while.

Cheers,

Michael

=======================================================================================

ell_rational_field.py:

Issue: This __dealloc__ method in mwrank.pyx doesn't clean up 100%:

cdef class _mw:
cdef mw* x
cdef Curvedata* curve

def __init__(self, _Curvedata curve, verb=False, pp=1, maxr=999):
self.curve = curve.x
self.x = mw_new(curve.x, verb, pp, maxr)

def __dealloc__(self):
mw_del(self.x)

mw_del in turn is in wrap.cc:

void mw_del(struct mw* m)
{
delete m;
}

Not sure why this leaks, but I have to poke around.

==12261== 28,816 bytes in 2 blocks are possibly lost in loss record
26,368 of 26,668
==12261== at 0x4A1C2F7: operator new[](unsigned long)
(vg_replace_malloc.c:274)
==12261== by 0x1B7873DD: mw::mw(Curvedata*, int, int, int)
(mwprocs.cc:245)
==12261== by 0x21066D28: mw_new (wrap.cc:140)
==12261== by 0x21066850:
__pyx_pf_4sage_4libs_6mwrank_6mwrank_3_mw___init__ (mwrank.c:1756)
==12261== by 0x459350: type_call (typeobject.c:436)
==12261== by 0x415832: PyObject_Call (abstract.c:1861)
==12261== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==12261== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==12261== by 0x4CF3F7: function_call (funcobject.c:517)
==12261== by 0x415832: PyObject_Call (abstract.c:1861)
==12261== by 0x41BF6C: instancemethod_call (classobject.c:2519)
==12261== by 0x415832: PyObject_Call (abstract.c:1861)
==12261== by 0x4565D7: slot_tp_init (typeobject.c:4943)
==12261== by 0x459350: type_call (typeobject.c:436)
==12261== by 0x415832: PyObject_Call (abstract.c:1861)
==12261== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==12261== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==12261== by 0x483F76: PyEval_EvalFrameEx (ceval.c:3669)
==12261== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==12261== by 0x484AF1: PyEval_EvalFrameEx (ceval.c:494)
==12261== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==12261== by 0x4CF3F7: function_call (funcobject.c:517)
==12261== by 0x415832: PyObject_Call (abstract.c:1861)
==12261== by 0x41BF6C: instancemethod_call (classobject.c:2519)
==12261== by 0x415832: PyObject_Call (abstract.c:1861)


Issue: We call

def do_descent(self, _Curvedata curve,
int verb = 1,
int sel = 0,
int firstlim = 20,
int secondlim = 8,
int n_aux = -1,
int second_descent = 1):
_sig_on
self.x = two_descent_new(curve.x, verb, sel, firstlim,
secondlim, n_aux, second_descent)
_sig_off

In this class in mwrank.pyx:

cdef class _two_descent:
cdef two_descent* x

def __init__(self):
self.x = <two_descent*> 0

def __dealloc__(self):
if self.x:
two_descent_del(self.x)

So either two_descent_del is not cleaning something up or we are it
leaking somehow in Cython. This is probably similar to the issue above
in wrap.cc

==12261== 28,816 bytes in 2 blocks are possibly lost in loss record
26,369 of 26,668
==12261== at 0x4A1C2F7: operator new[](unsigned long)
(vg_replace_malloc.c:274)
==12261== by 0x1B7873DD: mw::mw(Curvedata*, int, int, int)
(mwprocs.cc:245)
==12261== by 0x211FEE0C: two_descent::do_the_descent(long, long,
long, int) (descent.cc:104)
==12261== by 0x212000F1: two_descent::two_descent(Curvedata*, int,
int, long, long, long, int) (descent.cc:59)
==12261== by 0x21066C97: two_descent_new (wrap.cc:239)
==12261== by 0x21063AEC:
__pyx_pf_4sage_4libs_6mwrank_6mwrank_12_two_descent_do_descent
(mwrank.c:2704)
==12261== by 0x483E46: PyEval_EvalFrameEx (ceval.c:3573)
==12261== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==12261== by 0x483F76: PyEval_EvalFrameEx (ceval.c:3669)
==12261== by 0x48491B: PyEval_EvalFrameEx (ceval.c:3659)
==12261== by 0x48491B: PyEval_EvalFrameEx (ceval.c:3659)
==12261== by 0x48491B: PyEval_EvalFrameEx (ceval.c:3659)
==12261== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==12261== by 0x484AF1: PyEval_EvalFrameEx (ceval.c:494)
==12261== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==12261== by 0x4CF3F7: function_call (funcobject.c:517)
==12261== by 0x415832: PyObject_Call (abstract.c:1861)
==12261== by 0x41BF6C: instancemethod_call (classobject.c:2519)
==12261== by 0x415832: PyObject_Call (abstract.c:1861)
==12261== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==12261== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==12261== by 0x483F76: PyEval_EvalFrameEx (ceval.c:3669)
==12261== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==12261== by 0x4CF3F7: function_call (funcobject.c:517)
==12261== by 0x415832: PyObject_Call (abstract.c:1861)

While I am complaining:

/scratch/mabshoff/release-cycle/sage-3.2.2.rc1/devel/sage/sage/libs/
mwrank/mwrank.pyx
ERROR: Please define a s == loads(dumps(s)) doctest.
SCORE /scratch/mabshoff/release-cycle/sage-3.2.2.rc1/devel/sage/sage/
libs/mwrank/mwrank.pyx: 3% (1 of 29)

Missing documentation:
* set_precision(n):
* __init__(self, x="0"):
* __repr__(self):
* __init__(self, a1, a2, a3, a4, a6, min_on_init=0):
* __repr__(self):
* silverman_bound(self):
* cps_bound(self):
* height_constant(self):
* discriminant(self):
* conductor(self):
* isogeny_class(self, verbose=False):
* __init__(self, _Curvedata curve, verb=False, pp=1, maxr=999):
* __repr__(self):
* process(self, point, sat=True):
* getbasis(self):
* regulator(self):
* rank(self):
* saturate(self, int sat_bd=-1, int odd_primes_only=0):
* search(self, h_lim, int moduli_option=0, int verb=0):
* __init__(self):
* do_descent(self, _Curvedata curve, int verb = 1, int sel = 0, int
firstlim = 20, int secondlim = 8, int n_aux = -1, int second_descent =
1):
* getrank(self):
* getselmer(self):
* ok(self):
* getcertain(self):
* saturate(self, saturation_bound=0):
* getbasis(self):
* regulator(self):

But the code is ancient (i.e. it was written before SageX had C++
support, so you should get the idea) and IIRC William did once rewrite
it from scratch to a 95% finish. So it might be better to wait if
William can find that code.

=======================================================================================

newforms.pyx:

The issue: cdef class ECModularSymbol has an __init__ method, but no
deallocation code [This is SD 6 from Bristol and in the end William's
fault :)]

==30126== 208 (40 direct, 168 indirect) bytes in 1 blocks are
definitely lost in loss record 2,130 of 14,459
==30126== at 0x4A1C679: operator new(unsigned long)
(vg_replace_malloc.c:230)
==30126== by 0x1AFE6E2A: std::_Rb_tree<int, std::pair<int const,
int>, std::_Select1st<std::pair<int const, int> >, std::less<int>,
std::all
ocator<std::pair<int const, int> > >::_M_copy
(std::_Rb_tree_node<std::pair<int const, int> > const*,
std::_Rb_tree_node<std::pair<int const, in
t> >*) (new_allocator.h:88)
==30126== by 0x1B1DCCD2: std::vector<svec_i, std::allocator<svec_i>
>::operator=(std::vector<svec_i, std::allocator<svec_i> > const&)
(stl_t
ree.h:570)
==30126== by 0x1B1D6B0F: smat_i::operator=(smat_i const&) (smat.cc:
42)
==30126== by 0x1AFE3CC4: homspace::homspace(long, int, int, int)
(homspace.cc:348)
==30126== by 0x1AFEE6C9: newforms::makeh1() (newforms.cc:467)
==30126== by 0x1AFF1FE2: newforms::createfromcurves
(std::vector<CurveRed, std::allocator<CurveRed> >, int) (newforms.cc:
937)
==30126== by 0x1AFF28F1: newforms::createfromcurve(CurveRed, int)
(newforms.cc:929)
==30126== by 0x1AEBD930:
__pyx_pf_4sage_4libs_7cremona_8newforms_15ECModularSymbol___init__
(_object*, _object*, _object*) (newforms.cpp:1663
)
==30126== by 0x459350: type_call (typeobject.c:436)
==30126== by 0x415832: PyObject_Call (abstract.c:1861)
==30126== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==30126== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==30126== by 0x484AF1: PyEval_EvalFrameEx (ceval.c:494)
==30126== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==30126== by 0x4CF3F7: function_call (funcobject.c:517)
==30126== by 0x415832: PyObject_Call (abstract.c:1861)
==30126== by 0x41BF6C: instancemethod_call (classobject.c:2519)
==30126== by 0x415832: PyObject_Call (abstract.c:1861)
==30126== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==30126== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==30126== by 0x483F76: PyEval_EvalFrameEx (ceval.c:3669)
==30126== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==30126== by 0x4CF3F7: function_call (funcobject.c:517)
==30126== by 0x415832: PyObject_Call (abstract.c:1861)

==30126== 256 bytes in 1 blocks are possibly lost in loss record 9,655
of 14,459
==30126== at 0x4A1C679: operator new(unsigned long)
(vg_replace_malloc.c:230)
==30126== by 0x1AFEC34A: std::vector<long, std::allocator<long>
>::_M_insert_aux(__gnu_cxx::__normal_iterator<long*, std::vector<long,
std::
allocator<long> > >, long const&) (new_allocator.h:88)
==30126== by 0x1AFEB415: level::level(long, long) (stl_vector.h:
610)
==30126== by 0x1AFEBAEA: moddata::moddata(long) (moddata.cc:67)
==30126== by 0x1AFE9595: symbdata::symbdata(long) (symb.cc:134)
==30126== by 0x1AFE2944: homspace::homspace(long, int, int, int)
(homspace.cc:67)
==30126== by 0x1AFEE6C9: newforms::makeh1() (newforms.cc:467)
==30126== by 0x1AFF1FE2: newforms::createfromcurves
(std::vector<CurveRed, std::allocator<CurveRed> >, int) (newforms.cc:
937)
==30126== by 0x1AFF28F1: newforms::createfromcurve(CurveRed, int)
(newforms.cc:929)
==30126== by 0x1AEBD930:
__pyx_pf_4sage_4libs_7cremona_8newforms_15ECModularSymbol___init__
(_object*, _object*, _object*) (newforms.cpp:1663
)
==30126== by 0x459350: type_call (typeobject.c:436)
==30126== by 0x415832: PyObject_Call (abstract.c:1861)
==30126== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==30126== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==30126== by 0x484AF1: PyEval_EvalFrameEx (ceval.c:494)
==30126== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==30126== by 0x4CF3F7: function_call (funcobject.c:517)
==30126== by 0x415832: PyObject_Call (abstract.c:1861)
==30126== by 0x41BF6C: instancemethod_call (classobject.c:2519)
==30126== by 0x415832: PyObject_Call (abstract.c:1861)
==30126== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==30126== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==30126== by 0x483F76: PyEval_EvalFrameEx (ceval.c:3669)
==30126== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==30126== by 0x4CF3F7: function_call (funcobject.c:517)


==30126== 1,040 (40 direct, 1,000 indirect) bytes in 1 blocks are
definitely lost in loss record 12,597 of 14,459
==30126== at 0x4A1C679: operator new(unsigned long)
(vg_replace_malloc.c:230)
==30126== by 0x1AFE6E2A: std::_Rb_tree<int, std::pair<int const,
int>, std::_Select1st<std::pair<int const, int> >, std::less<int>,
std::all
ocator<std::pair<int const, int> > >::_M_copy
(std::_Rb_tree_node<std::pair<int const, int> > const*,
std::_Rb_tree_node<std::pair<int const, in
t> >*) (new_allocator.h:88)
==30126== by 0x1AFE6F76: std::_Rb_tree<int, std::pair<int const,
int>, std::_Select1st<std::pair<int const, int> >, std::less<int>,
std::all
ocator<std::pair<int const, int> > >::operator=(std::_Rb_tree<int,
std::pair<int const, int>, std::_Select1st<std::pair<int const, int>
>, std:
:less<int>, std::allocator<std::pair<int const, int> > > const&)
(stl_tree.h:800)
==30126== by 0x1AFE32B6: homspace::homspace(long, int, int, int)
(stl_map.h:227)
==30126== by 0x1AFEE6C9: newforms::makeh1() (newforms.cc:467)
==30126== by 0x1AFF1FE2: newforms::createfromcurves
(std::vector<CurveRed, std::allocator<CurveRed> >, int) (newforms.cc:
937)
==30126== by 0x1AFF28F1: newforms::createfromcurve(CurveRed, int)
(newforms.cc:929)
==30126== by 0x1AEBD930:
__pyx_pf_4sage_4libs_7cremona_8newforms_15ECModularSymbol___init__
(_object*, _object*, _object*) (newforms.cpp:1663
)
==30126== by 0x459350: type_call (typeobject.c:436)
==30126== by 0x415832: PyObject_Call (abstract.c:1861)
==30126== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==30126== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==30126== by 0x484AF1: PyEval_EvalFrameEx (ceval.c:494)
==30126== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==30126== by 0x4CF3F7: function_call (funcobject.c:517)
==30126== by 0x415832: PyObject_Call (abstract.c:1861)
==30126== by 0x41BF6C: instancemethod_call (classobject.c:2519)
==30126== by 0x415832: PyObject_Call (abstract.c:1861)
==30126== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==30126== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==30126== by 0x483F76: PyEval_EvalFrameEx (ceval.c:3669)
==30126== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==30126== by 0x4CF3F7: function_call (funcobject.c:517)
==30126== by 0x415832: PyObject_Call (abstract.c:1861)
==30126== by 0x41BF6C: instancemethod_call (classobject.c:2519)

==30126== 1,904 bytes in 1 blocks are possibly lost in loss record
14,016 of 14,459
==30126== at 0x4A1C679: operator new(unsigned long)
(vg_replace_malloc.c:230)
==30126== by 0x1B1DCC5F: std::vector<svec_i, std::allocator<svec_i>
>::operator=(std::vector<svec_i, std::allocator<svec_i> > const&)
(new_a
llocator.h:88)
==30126== by 0x1B1D6B0F: smat_i::operator=(smat_i const&) (smat.cc:
42)
==30126== by 0x1AFE3CC4: homspace::homspace(long, int, int, int)
(homspace.cc:348)
==30126== by 0x1AFEE6C9: newforms::makeh1() (newforms.cc:467)
==30126== by 0x1AFF1FE2: newforms::createfromcurves
(std::vector<CurveRed, std::allocator<CurveRed> >, int) (newforms.cc:
937)
==30126== by 0x1AFF28F1: newforms::createfromcurve(CurveRed, int)
(newforms.cc:929)
==30126== by 0x1AEBD930:
__pyx_pf_4sage_4libs_7cremona_8newforms_15ECModularSymbol___init__
(_object*, _object*, _object*) (newforms.cpp:1663
)
==30126== by 0x459350: type_call (typeobject.c:436)
==30126== by 0x415832: PyObject_Call (abstract.c:1861)
==30126== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==30126== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==30126== by 0x484AF1: PyEval_EvalFrameEx (ceval.c:494)
==30126== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==30126== by 0x4CF3F7: function_call (funcobject.c:517)
==30126== by 0x415832: PyObject_Call (abstract.c:1861)
==30126== by 0x41BF6C: instancemethod_call (classobject.c:2519)
==30126== by 0x415832: PyObject_Call (abstract.c:1861)
==30126== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==30126== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==30126== by 0x483F76: PyEval_EvalFrameEx (ceval.c:3669)
==30126== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==30126== by 0x4CF3F7: function_call (funcobject.c:517)
==30126== by 0x415832: PyObject_Call (abstract.c:1861)
==30126== by 0x41BF6C: instancemethod_call (classobject.c:2519)

=======================================================================================

padics.pyx - this exposes the same problem as in newforms.pyx

==4475== 232 (40 direct, 192 indirect) bytes in 1 blocks are
definitely lost in loss record 11,355 of 25,692
==4475== at 0x4A1C679: operator new(unsigned long)
(vg_replace_malloc.c:230)
==4475== by 0x1AEBD6C4:
__pyx_pf_4sage_4libs_7cremona_8newforms_15ECModularSymbol___init__
(_object*, _object*, _object*) (newforms.cpp:1600)
==4475== by 0x459350: type_call (typeobject.c:436)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==4475== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==4475== by 0x4CF390: function_call (funcobject.c:517)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x41BF6C: instancemethod_call (classobject.c:2519)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x4565D7: slot_tp_init (typeobject.c:4943)
==4475== by 0x459350: type_call (typeobject.c:436)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==4475== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==4475== by 0x483F76: PyEval_EvalFrameEx (ceval.c:3669)
==4475== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==4475== by 0x484AF1: PyEval_EvalFrameEx (ceval.c:494)
==4475== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==4475== by 0x4CF3F7: function_call (funcobject.c:517)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x41BF6C: instancemethod_call (classobject.c:2519)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==4475== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)

==4475== 944 (200 direct, 744 indirect) bytes in 1 blocks are
definitely lost in loss record 18,977 of 25,692
==4475== at 0x4A1C679: operator new(unsigned long)
(vg_replace_malloc.c:230)
==4475== by 0x1AEBD772:
__pyx_pf_4sage_4libs_7cremona_8newforms_15ECModularSymbol___init__
(_object*, _object*, _object*) (newforms.cpp:1618)
==4475== by 0x459350: type_call (typeobject.c:436)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==4475== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==4475== by 0x4CF390: function_call (funcobject.c:517)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x41BF6C: instancemethod_call (classobject.c:2519)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x4565D7: slot_tp_init (typeobject.c:4943)
==4475== by 0x459350: type_call (typeobject.c:436)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==4475== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==4475== by 0x483F76: PyEval_EvalFrameEx (ceval.c:3669)
==4475== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==4475== by 0x484AF1: PyEval_EvalFrameEx (ceval.c:494)
==4475== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==4475== by 0x4CF3F7: function_call (funcobject.c:517)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x41BF6C: instancemethod_call (classobject.c:2519)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==4475== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)


==4475== 440 bytes in 1 blocks are possibly lost in loss record 18,981
of 25,692
==4475== at 0x4A1BE1B: malloc (vg_replace_malloc.c:207)
==4475== by 0x4B1539: _PyObject_GC_Malloc (gcmodule.c:1321)
==4475== by 0x4B162F: _PyObject_GC_NewVar (gcmodule.c:1353)
==4475== by 0x4CEA3D: PyFrame_New (frameobject.c:614)
==4475== by 0x485875: PyEval_EvalCodeEx (ceval.c:2631)
==4475== by 0x4CF3F7: function_call (funcobject.c:517)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x41BF6C: instancemethod_call (classobject.c:2519)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x1AEBD5BD:
__pyx_pf_4sage_4libs_7cremona_8newforms_15ECModularSymbol___init__
(_object*, _object*, _object*) (newforms.cpp:1582)
==4475== by 0x459350: type_call (typeobject.c:436)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==4475== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==4475== by 0x4CF390: function_call (funcobject.c:517)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x41BF6C: instancemethod_call (classobject.c:2519)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x4565D7: slot_tp_init (typeobject.c:4943)
==4475== by 0x459350: type_call (typeobject.c:436)
==4475== by 0x415832: PyObject_Call (abstract.c:1861)
==4475== by 0x482DB9: PyEval_EvalFrameEx (ceval.c:3784)
==4475== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)
==4475== by 0x483F76: PyEval_EvalFrameEx (ceval.c:3669)
==4475== by 0x485DB1: PyEval_EvalCodeEx (ceval.c:2836)

[John Cremona]

OK, so one of my new year's resolutions should be to get to grips with
the code wrapping eclib (including mwrank etc) since my tentative
moves in that direction have never got very far. I feel that I should
take responsibility for this. If not before, then this will be my
task for Sage Days 15 in Barcelona (I know that I will not be able to
get to any before that).

About the memory thing I mentioned before, if all you do is this:
sage: for E in cremona_curves(range(11,10000)):
print E.cremona_label()

then the RAM usage (as reported by "top") creeps up to 670MB or so. While

sage: for E in cremona_curves(range(11,10000)):
print E.cremona_label(), E.pari_curve()[:5]

(in a fresh session) goes up to 821 MB, and

sage: for E in cremona_curves(range(11,10000)):
print E.cremona_label(), ld=E.local_data()

hits 800MB by conductor 2000, 1.2GB by 3000, 1.7GB by 4000 and then I
killed it as the machine (32-bit) has 2GB of RAM and if I let it go
further even killing the process is a problem as all the windows
freeze up.

This is a nuisance as it makes mass testing harder. Should it be
happening at all? Are we caching too agressively? To my mind, in a
loop such as this, we do not need to keep any data about any curve in
a cache once we are processing the next curve in the loop.

[This is possibly not really a sage-nt issue!]

John

2008/12/16 mabshoff <mabs...@googlemail.com>:

[William Stein]

It's sitting here:

http://trac.sagemath.org/sage_trac/ticket/1949

--
William Stein
Associate Professor of Mathematics
University of Washington
http://wstein.org

[William Stein]

On Tue, Dec 16, 2008 at 3:43 AM, John Cremona <john.c...@gmail.com> wrote:
>
> OK, so one of my new year's resolutions should be to get to grips with
> the code wrapping eclib (including mwrank etc) since my tentative
> moves in that direction have never got very far. I feel that I should
> take responsibility for this. If not before, then this will be my
> task for Sage Days 15 in Barcelona (I know that I will not be able to
> get to any before that).
>
> About the memory thing I mentioned before, if all you do is this:
> sage: for E in cremona_curves(range(11,10000)):
> print E.cremona_label()
>
> then the RAM usage (as reported by "top") creeps up to 670MB or so. While
>
> sage: for E in cremona_curves(range(11,10000)):
> print E.cremona_label(), E.pari_curve()[:5]
>
> (in a fresh session) goes up to 821 MB, and
>
> sage: for E in cremona_curves(range(11,10000)):
> print E.cremona_label(), ld=E.local_data()
>
> hits 800MB by conductor 2000, 1.2GB by 3000, 1.7GB by 4000 and then I
> killed it as the machine (32-bit) has 2GB of RAM and if I let it go
> further even killing the process is a problem as all the windows
> freeze up.
>
> This is a nuisance as it makes mass testing harder. Should it be
> happening at all? Are we caching too agressively? To my mind, in a
> loop such as this, we do not need to keep any data about any curve in
> a cache once we are processing the next curve in the loop.

This should not happen. That it does seriously sucks. I definitely
consider it a bug, and it does cause me problems on occasion.

William

[mabshoff]

On Dec 16, 8:01 am, "William Stein" <wst...@gmail.com> wrote:

<SNIP>

> > But the code is ancient (i.e. it was written before SageX had C++
> > support, so you should get the idea) and IIRC William did once rewrite
> > it from scratch to a 95% finish. So it might be better to wait if
> > William can find that code.
>
> It's sitting here:
>
> http://trac.sagemath.org/sage_trac/ticket/1949

Ok, I will check it out then. It does seem to require a bit of work
since it doesn't even compile yet (according to the notes), so this is
certainly also far away from me.

> --
> William Stein

Cheers,

Michael

[mabshoff]

On Dec 16, 8:03 am, "William Stein" <wst...@gmail.com> wrote:
> On Tue, Dec 16, 2008 at 3:43 AM, John Cremona <john.crem...@gmail.com> wrote:

Hi,

> > OK, so one of my new year's resolutions should be to get to grips with
> > the code wrapping eclib (including mwrank etc) since my tentative
> > moves in that direction have never got very far.  I feel that I should
> > take responsibility for this.  If not before, then this will be my
> > task for Sage Days 15 in Barcelona (I know that I will not be able to
> > get to any before that).

Well, I posted to sage-nt since I was hoping that someone who did a
lof of computations in this area would be willing to pitch in. The
signal to noise ratio here is much better for those specific problems.
I don't know if I have mentioned this, but I have known about those
specific leaks for about nine months, but nobody ever complained about
them to me and there were usually always bigger fires to put out
elsewhere.

<SNIP>

I will poke around with the examples to see if there is anything
obvious to fix here.

> > This is a nuisance as it makes mass testing harder.  Should it be
> > happening at all?  Are we caching too agressively?  To my mind, in a
> > loop such as this, we do not need to keep any data about any curve in
> > a cache once we are processing the next curve in the loop.
>
> This should not happen.  That it does seriously sucks.  I definitely
> consider it a bug, and it does cause me problems on occasion.

+1 - this is absolutely unacceptable that Sage craps out like that
just by doing computations for a bunch of elliptic curves. The
newforms.pyx is currently the largest single "definitely lost" doctest
in Sage right now [there are much worse, but valgrind considers those
cases "memory not release at exit", so newform.pyx gets to win here on
a technicality :)]

Anyway, I was hoping since I raised the issue here that we might do
something about it soon and if not this is something I might spend
time on during SD12.

> William

Cheers,

Michael

[mabshoff]

On Dec 16, 3:43 am, "John Cremona" <john.crem...@gmail.com> wrote:

Hi,

> OK, so one of my new year's resolutions should be to get to grips with
> the code wrapping eclib (including mwrank etc) since my tentative
> moves in that direction have never got very far.  I feel that I should
> take responsibility for this.  If not before, then this will be my
> task for Sage Days 15 in Barcelona (I know that I will not be able to
> get to any before that).
>
> About the memory thing I mentioned before,  if all you do is this:
> sage: for E in cremona_curves(range(11,10000)):
>     print E.cremona_label()
>
> then the RAM usage (as reported by "top") creeps up to 670MB or so.  While
>
> sage: for E in cremona_curves(range(11,10000)):
>     print E.cremona_label(), E.pari_curve()[:5]
>
> (in a fresh session) goes up to 821 MB, and
>
> sage: for E in cremona_curves(range(11,10000)):
>     print E.cremona_label(), ld=E.local_data()
>
> hits 800MB by conductor 2000, 1.2GB by 3000, 1.7GB by 4000 and then I
> killed it as the machine (32-bit) has 2GB of RAM and if I let it go
> further even killing the process is a problem as all the windows
> freeze up.
>
> This is a nuisance as it makes mass testing harder.  Should it be
> happening at all?  Are we caching too agressively?  To my mind, in a
> loop such as this, we do not need to keep any data about any curve in
> a cache once we are processing the next curve in the loop.
>
> [This is possibly not really a sage-nt issue!]

Probably, but it is fun to discuss here nonetheless :)

> John

The above problems are fixed in 3.2.2.rc1: To illustrate I ran all of
the example code in 3.2.1 with the new Cython 0.10.2p0 vs. vanilla
3.2.1. Speed did improve enormously (up tp 10 times) while the leak
reduction was in one example a factor of *200*:

base=get_memory_usage()
time for E in cremona_curves(range(11,10000)): print E.cremona_label()
get_memory_usage()-base

This leaks 41 MB and takes 45.20 s (3.2.1 + new Cython) vs. 1,085 MB
in 235s (3.2.1)

-----

base=get_memory_usage()
time for E in cremona_curves(range(11,10000)): print E.cremona_label
(), E.pari_curve()[:5]
get_memory_usage()-base

This leaks 42 MB and takes 109.88 s (3.2.1 + new Cython) vs. 1,354 MB
in 298.17s (3.2.1)

-----

base=get_memory_usage()
time for E in cremona_curves(range(11,10000)): print E.cremona_label
(); ld=E.local_data()
get_memory_usage()-base

This leaks 44 MB and takes 682.67 s (3.2.1 + new Cython) vs. 8,004 MB
in 6815.76 s (3.2.1)

[10 times performance while reducing the leak by a factor of *200* -
note that the old code visibly paused every couple dozen curves or so
while the new code just scrolls by]

-----

So John, if you haven't already dropped in the new cython.spkg from
3.2.2.rc0 into your working installation and done a -ba I would highly
recommend it. I would certainly recommend patting RobertWB on the back
and buying him dinner if you see him around the next couple days for
fixing this and another highly critical issue in 3.2.2.

Cheers,

Michael

[mabshoff]

On Dec 16, 7:00 pm, mabshoff <mabsh...@googlemail.com> wrote:

[Sorry for spamming the list somewhat :)]

<SNIP>

> So John, if you haven't already dropped in the new cython.spkg from
> 3.2.2.rc0 into your working installation and done a -ba I would highly
> recommend it. I would certainly recommend patting RobertWB on the back
> and buying him dinner if you see him around the next couple days for
> fixing this and another highly critical issue in 3.2.2.

What is even more important and I don't think I made 100% clear is
that with 3.2.2.rc1 you will see that reunning any kind of enumeration
again will not increase the amount of memory used by Sage (modulo
other leaks you might hit). I.e. look at the following two sessions:

mabshoff@sage:/scratch/mabshoff/release-cycle/sage-3.2.2.rc1$ ./sage
----------------------------------------------------------------------
| Sage Version 3.2.2.rc0, Release Date: 2008-12-15 |
| Type notebook() for the GUI, and license() for information. |
----------------------------------------------------------------------
sage: base=get_memory_usage()
sage: time for E in cremona_curves(range(11,1000)): E.cremona_label()
CPU times: user 3.08 s, sys: 0.08 s, total: 3.17 s
Wall time: 3.17 s
sage: get_memory_usage()-base
9.3359375
sage: deltabase=get_memory_usage()
sage: time for E in cremona_curves(range(11,1000)): E.cremona_label()
CPU times: user 2.92 s, sys: 0.07 s, total: 2.99 s
Wall time: 2.99 s
sage: get_memory_usage()-base
9.3359375
sage: get_memory_usage()-deltabase
0.0
sage:
Exiting SAGE (CPU time 0m6.24s, Wall time 0m12.42s).

The second run did not consume any additional memory which is the way
it should be.


mabshoff@sage:/scratch/mabshoff/release-cycle/sage-3.2.2.rc1$ sage
----------------------------------------------------------------------
| Sage Version 3.2.1, Release Date: 2008-12-01 |
| Type notebook() for the GUI, and license() for information. |
----------------------------------------------------------------------
sage: base=get_memory_usage()
sage: time for E in cremona_curves(range(11,1000)): E.cremona_label()
CPU times: user 6.41 s, sys: 0.32 s, total: 6.73 s
Wall time: 6.73 s
sage: get_memory_usage()-base
87.0
sage: deltabase=get_memory_usage()
sage: time for E in cremona_curves(range(11,1000)): E.cremona_label()
CPU times: user 6.51 s, sys: 0.22 s, total: 6.73 s
Wall time: 6.74 s
sage: get_memory_usage()-base
160.44921875
sage: get_memory_usage()-deltabase
73.44921875

While here the second run did increase memory consumption further and
rerunning it a couple more times will always consume additional
memory.

> Cheers,
>
> Michael

I would be curious how the S-integral point counting code performs
with and without the new Cython + #4639, but I guess once I get some
sleep I will find out myself unless someone beats me to it.

Cheers,

Michael

[John Cremona]

Looking very good! I tested with 3.2.2.rc0 and saw the improvement
looping over all curves in range(11,10000). (You mentioned 3.2.2.rc1,
did you mean that?)

It now takes me even less time to find examples where S_integral_points crashes:
EllipticCurve('2534g1').Sintegral_points([2])
...
ZeroDivisionError: cannot divide by zero

so I'll get back to looking at that.

I would be very happy to buy Robert B a meal next time he's in
Kenilworth (where I live -- and not the one in New Jersey!) or when
our paths next cross. Can you point me to the ticket with the patches
where these miracles were done?

John

2008/12/17 mabshoff <mabs...@googlemail.com>:

[mabshoff]

On Dec 17, 3:21 am, "John Cremona" <john.crem...@gmail.com> wrote:

Hi John,

> Looking very good!  I tested with 3.2.2.rc0 and saw the improvement
> looping over all curves in range(11,10000).  (You mentioned 3.2.2.rc1,
> did you mean that?)

Yes, the Cython update is already in rc0, but I tested my rc1 merge
tree which has a coercion system leak fix also. But that does not seem
to have any measurable impact in this computation, but in other I have
seen significant improvements.

> It now takes me even less time to find examples where S_integral_points crashes:
> EllipticCurve('2534g1').Sintegral_points([2])
> ...
> ZeroDivisionError: cannot divide by zero
>
> so I'll get back to looking at that.

:)

> I would be very happy to buy Robert B a meal next time he's in
> Kenilworth (where I live -- and not the one in New Jersey!)

I would think you would get a chance at SD Barcelona unless RobertWB
is visiting you in the meantime :)

> or when
> our paths next cross.  Can you point me to the ticket with the patches
> where these miracles were done?

It is the new Cython.spkg at #4798. The more informative ticket is in
Cython's trac at

http://trac.cython.org/cython_trac/ticket/162#comment:3

The reason we never properly identified the problem was that the
memory is "trapped" in the Cython heap where the current valgrind
based memchecking doesn't really help beyond determining that we have
a problem. RobertWB then tracked it down and eventually found the
problem which was introduced in Cython 0.10.0 IIRC.

> John

Cheers,

Michael