[Zope3-dev] Intermittent failures in WeakRef doctest

[Tim Peters]

[Dave Harris]
> A week ago, I reported intermittent failures of the WeakRef doctest.
>
> (http://mail.zope.org/pipermail/zope3-dev/2004-January/009431.html)
>
> I didn't get any advice on my testing process, so I set it aside for a
> while. After all, I was overjoyed to get the unit tests running
> cleanly under Windows XP.
>
> But still, every now and then, the WeakRef failure pops up, spoiling
> my perfect score. Today, I dug a little deeper and distilled the
> doctest from wref.py into a looping script (see below.)
>
> Under Windows XP, the failure rate is about 65%. That is, the
> dereference returns None about 35% of the time and an empty list '[]'
> about 65% of the time.

On my Win98SE box, your script returns None about 10% of the time.  However,
no Linux-head has ever written a test involving pack() that actually works
all the time on Windows, so don't despair.  These are easy to fix.

> I'm still gathering information about the internal goings-on, and
> I'll pass along what I find.
>
> "What is my quest? I seek the fragile WeakRef!"
> Dave Harris
>
> Here's the script:
>
> # wref test based on wref.py doctest
> # 2004-01-24
>
> import persistence.list
> from persistence.wref import WeakRef
> import zodb.tests.util
>
> nones = 0
> lists = 0
>
> for i in range(100):
>     ob = persistence.list.PersistentList()
>     ref = WeakRef(ob)
>
>     db = zodb.tests.util.DB()
>
>     conn1 = db.open()
>     r1 = conn1.root()
>     r1['ob'] = ob
>     r1['ref'] = ref
>     zodb.tests.util.commit()
>
>     del r1['ob']
>     zodb.tests.util.commit()
>     zodb.tests.util.pack(db)

That's the problem.  If you add

from zodb.storage.tests.base import snooze

to the top of the script, and then call snooze() between the commit and the
pack, the test should return None 100% of the time (but it will also run
much slower, taking at least 10 seconds).  The reason is explained in a
comment at the start of the snooze() function.

>
>     conn3 = db.open()
>     r3 = conn3.root()
>
>     if r3['ref']() == None:
>         nones += 1
>     else:
>         lists += 1
>
>     db.close()
>
> print "ref() == None %s times, ref() == [] %s times" % (nones, lists)

Note that Windows-specific sporadic failures in new tests involving pack are
very common, but almost purely just a nuisance:  they're artifacts of
testing.  In real life, people pack to a granularity of days, but testing
provokes distinctions based on fractions of a second.  time.time() only
updates 18.2 times per second on most Windows boxes, so especially as
machines have gotten faster, it's become increasingly common that multiple
calls to time.time() return exactly the same value on Windows.  This doesn't
usually happen on Linux boxes (yet <wink>), because they typically update
time.time() a million times per second.

BTW, there are a number of inconsistent claims scattered around about what
pack does with an object whose modification time is *exactly* equal to the
pack time (both types of time are ultimately derived from the platform
time.time()).  I don't know the truth about that anymore, and it's hard to
care precisely because it only matters in test suites.  The snooze()
function keeps calling time.time() until the return value finally changes,
and that's enough to save a pack test from caring about the tennsy but
crucial difference between "<" and "<=".