[Python-bugs-list] [ python-Bugs-574132 ] Major GC related performance regression
noreply@sourceforge.net
noreply@sourceforge.net
Fri, 28 Jun 2002 07:50:33 -0700
Bugs item #574132, was opened at 2002-06-26 10:33
You can respond by visiting:
https://sourceforge.net/tracker/?func=detail&atid=105470&aid=574132&group_id=5470
Category: Python Interpreter Core
Group: Python 2.3
Status: Open
Resolution: None
Priority: 5
Submitted By: Kevin Jacobs (jacobs99)
Assigned to: Nobody/Anonymous (nobody)
Summary: Major GC related performance regression
Initial Comment:
A change in the Python 2.3 CVS tree has resulted
in a major performance regression. It shows up
when allocating large lists of objects, but only when
the garbage collector is enabled. I've attached a simple
script that I use to measure the time it takes to
incrementally append a large number of objects into
a single Python list. For previous versions of
Python (up to and including 2.2.1), the time scaled
linearly with the number of elements added to the
list (or close enough for the list sizes considered).
However, with the Python 2.3 CVS version,
the time required to build the list scales quadratically.
Here is the core of my benchmark:
rows = []
start = time.time()
for i in indices:
rows.append( (1,) )
See the attached file for the full source as well
as timing results for several versions of Python
with and without garbage collection enabled.
----------------------------------------------------------------------
>Comment By: Kevin Jacobs (jacobs99)
Date: 2002-06-28 09:50
Message:
Logged In: YES
user_id=459565
Here is a detailed analysis of the problem, using the following
kernel:
lst = []
for i in range(100000):
lst.append( (1,) )
The key ingredients are:
1) A method is called on a container (rather than
__setitem__ or
__setattr__).
2) A new object is allocated while the method object lives on
the Python
VM stack, as shown by the disassembled bytecodes:
40 LOAD_FAST 1 (lst)
43 LOAD_ATTR 3 (append)
46 LOAD_CONST 2 (1)
49 BUILD_TUPLE 1
52 CALL_FUNCTION 1
These ingredients combine in the following way to trigger
quadratic-time
behavior in the Python garbage collector:
* First, the LOAD_ATTR on "lst" for "append" is called, and
a PyCFunction
is returned from this code in descrobject.c:method_get:
return PyCFunction_New(descr->d_method, obj);
Thus, a _new_ PyCFunction is allocated every time the
method is
requested.
* This new method object is added to generation 0 of the
garbage
collector, which holds a reference to "lst".
* The BUILD_TUPLE call may then trigger a garbage
collection cycle.
* Since the "append" method is in generation 0, the
reference traversal
must also follow all objects within "lst", even if "lst" is in
generation 1 or 2. This traversal requires time linear in the
number of
objects in "lst", thus increasing the overall time complexity
of the
code to quadratic in the number of elements in "lst".
Also note that this is a much more general problem than this
small example.
It can affect many types of objects in addition to methods,
including
descriptors, iterator objects, and any other object that
contains a "back
reference".
So, what can be done about this.... One simple solution
would be to not
traverse some "back references" if we are collecting objects
in generation
0. This will avoid traversing virtually all of these ephemoral
objects that
will trigger such expensive behavior. If they live long enough
to pass
through to generation one or two, then clearly they should be
traversed.
So, what do all of you GC gurus think? Provided that my
analysis is sound,
I can rapidly propose a patch to demonstrate this approach if
there is
sufficient positive sentiment.
PS: I have not looked into why this doesn't happen in Python
2.2.x or
before. I suspect that it must be related to the recent GC
changes in
methodobject.py. I'm not motivated to spend much time
looking into
this, because the current GC behavior is technically
correct, though
clearly sub-optimal.
----------------------------------------------------------------------
Comment By: Jeremy Hylton (jhylton)
Date: 2002-06-26 23:10
Message:
Logged In: YES
user_id=31392
The first 4 run calls in this test spenned 70 percent of
their time in visit_move().
----------------------------------------------------------------------
You can respond by visiting:
https://sourceforge.net/tracker/?func=detail&atid=105470&aid=574132&group_id=5470