Is this a bug? Python intermittently stops dead for seconds

[charlie strauss]

Below is a simple program that will cause python to intermittently  
stop executing for a few seconds.  it's 100% reproducible on my machine.

I'd be tempted to say this is a nasty garbage collection performance  
issue except that there is no major memory to be garbage collected in  
this script.  I'd be tempted to say it was a unix virtual memory  
issue except this is occuring at around 1/5th of my physical memory  
size.  So something else unexplained is going on

Class Foo instances create and hold a list  of size nfoo of integers.  
(nfoo =10)

Class Bar instances create and hold a list of size nbar of Foo  
objects. (nbar =100)

When the code runs it starts creating and storing Bar objects in a  
list while watching for real-time glitches in how long it takes to  
create the next Foo object.  If this is longer than 1/2 of a second  
then it reports it.

On my computer  after creating 1500 Bar objects,  the rate of  
creation of new Foo  suddenly has a  periodic glitch.  This glitch re- 
occurs about every 300 Bar Objects, and the duration of the glitch  
keeps getting longer--growing to many seconds!!!!

Platform: 800Mhz powermac g 4  1Gb of memory
python:  python 2.4.2

Note: since I an using absolute time threshold for reporting the  
glitches, the first one may take more iterations before it occurs on  
a fast computer.  You may need to increase nbar or nfoo.

import sys
from time import time


class Foo(object):
     def __init__(me,nfoo):
         me.memory = [1]*nfoo

class Bar(object):
     def __init__(me,nbar,nfoo):
         tgx.set_tag("Bar")  # timer

         b = [None]*nbar
         for i in xrange(nbar):
             b[i]=Foo(nfoo)  # make a foo, add it to list
             tgx.jump("Bar"+`i`)  #timer

         me.b = b  #store the list in my instance memory




# just a utility class to time things.
class gtime:
     def __init__(me,f=sys.stderr):
         me.last = time()
         me.f=f
         me.tag = ""
         me.ticks = 0

     def set_tag(me,tag):
         me.tag = tag
         me.ticks = 0

     def reset(me):
         me.ticks = 0

     def jump(me,tag="NONE",allowed_gap=0.5):
         me.t = time()
         me.ticks +=1
         if me.t-me.last>allowed_gap:
             print >>me.f,"Big Gap:",me.t-me.last,"seconds    
",me.tag,tag,me.ticks
         me.last = time()

tgx = gtime() # instance of the timer


# main loop
nbar = 100
nfoo = 10

ad_nauseum = 20000
final = [None]*ad_nauseum

for i in xrange(ad_nauseum ):
     if i%100 == 0 :print >>sys.stderr,"Bars Made: ",i
     final[i] = Bar(nbar,nfoo)



sample Output:

Bars Made:  0
Bars Made:  100
Bars Made:  200
Bars Made:  300
Bars Made:  400
Bars Made:  500
Bars Made:  600
Bars Made:  700
Bars Made:  800
Bars Made:  900
Bars Made:  1000
Bars Made:  1100
Bars Made:  1200
Bars Made:  1300
Bars Made:  1400
Bars Made:  1500
Big Gap: 0.618862867355 seconds    Bar Bar5 6
Bars Made:  1600
Bars Made:  1700
Bars Made:  1800
Big Gap: 0.748915195465 seconds    Bar Bar76 77
Bars Made:  1900
Bars Made:  2000
Bars Made:  2100
Big Gap: 0.809149980545 seconds    Bar Bar45 46
Bars Made:  2200
Bars Made:  2300
Bars Made:  2400
Big Gap: 0.898494958878 seconds    Bar Bar15 16
Bars Made:  2500
Bars Made:  2600
Bars Made:  2700
Big Gap: 1.01110696793 seconds    Bar Bar86 87
Bars Made:  2800
Bars Made:  2900
Bars Made:  3000
Big Gap: 1.12396192551 seconds    Bar Bar55 56
Bars Made:  3100
Bars Made:  3200
Bars Made:  3300
Big Gap: 1.39006495476 seconds    Bar Bar25 26
Bars Made:  3400
Bars Made:  3500
Bars Made:  3600
Big Gap: 1.55699706078 seconds    Bar Bar96 97
Bars Made:  3700
Bars Made:  3800
Bars Made:  3900
Big Gap: 1.49929594994 seconds    Bar Bar65 66
Bars Made:  4000
Bars Made:  4100
Bars Made:  4200
Big Gap: 1.64840602875 seconds    Bar Bar35 36
Bars Made:  4300
Bars Made:  4400
Bars Made:  4500
Big Gap: 1.728484869 seconds    Bar Bar5 6
Bars Made:  4600
Bars Made:  4700
Bars Made:  4800