[tahoe-dev] Test failure with 1.6.1

Ludovic Courtès ludo at gnu.org
Mon Mar 1 05:11:32 PST 2010 

Hello,

I’m seeing this test failure with 1.6.1:

--8<---------------cut here---------------start------------->8---
[ERROR]: allmydata.test.test_immutable.Test.test_download_abort_if_too_many_corrupted_shares

Traceback (most recent call last):
  File "/nix/store/bjyli4vn66xdr1iy4nd0macgf2qszlrk-python-twisted-8.2.0/lib/python2.6/site-packages/Twisted-8.2.0-py2.6-linux-x86_64.egg/twisted/internet/defer.py", line 106, in maybeDeferred
    result = f(*args, **kw)
  File "/tmp/nix-build-r96hdx3aqflfpz3n42ahnxr3h47pgb99-tahoe-lafs-1.6.1.drv-0/allmydata-tahoe-1.6.1/src/allmydata/util/pollmixin.py", line 34, in _poll
    raise TimeoutError("PollMixin never saw %s return True" % check_f)
allmydata.util.pollmixin.TimeoutError: PollMixin never saw <bound method Test._check_connections of <allmydata.test.test_immutable.Test testMethod=test_download_abort_if_too_many_corrupted_shares>> return True
===============================================================================
[ERROR]: allmydata.test.test_immutable.Test.test_download_abort_if_too_many_corrupted_shares

Traceback (most recent call last):
Failure: twisted.trial.util.DirtyReactorAggregateError: Reactor was unclean.
DelayedCalls: (set twisted.internet.base.DelayedCall.debug = True to debug)
<DelayedCall 112697568 [0.306632995605s] called=0 cancelled=0 _resetLogDateTime()>
<DelayedCall 73295056 [39.0011720657s] called=0 cancelled=0 LoopingCall<60>(CPUUsageMonitor.check, *(), **{})()>
<DelayedCall 124668888 [12.2756268978s] called=0 cancelled=0 Client.failIfNotConnected(TimeoutError('',))>
<DelayedCall 107045664 [40.8682770729s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 85166128 [39.9848210812s] called=0 cancelled=0 LoopingCall<60>(CPUUsageMonitor.check, *(), **{})()>
<DelayedCall 112701240 [39.9656379223s] called=0 cancelled=0 LoopingCall<60>(CPUUsageMonitor.check, *(), **{})()>
<DelayedCall 98078232 [40.9274890423s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 68118144 [41.9416329861s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 74581776 [41.9108128548s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 119754264 [40.8470869064s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 76254312 [40.4103829861s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 85164976 [40.0300681591s] called=0 cancelled=0 LoopingCall<60>(CPUUsageMonitor.check, *(), **{})()>
<DelayedCall 65439432 [40.0746109486s] called=0 cancelled=0 LoopingCall<60>(CPUUsageMonitor.check, *(), **{})()>
<DelayedCall 124657320 [41.8686709404s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 79222976 [42.2958297729s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 82108288 [159.000748873s] called=0 cancelled=0 LeaseCheckingCrawler.start_slice()>
<DelayedCall 78690928 [42.4404137135s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 68166936 [3399.00077176s] called=0 cancelled=0 LoopingCall<3600>(CacheDirectoryManager.check, *(), **{})()>
<DelayedCall 118935352 [100.075267076s] called=0 cancelled=0 BucketCountingCrawler.start_slice()>
<DelayedCall 61756192 [99.0004661083s] called=0 cancelled=0 BucketCountingCrawler.start_slice()>
<DelayedCall 76253448 [41.8520348072s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 99126952 [40.7562129498s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 99306744 [40.7746968269s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 74948832 [40.7412917614s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 88674384 [40.6218450069s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 88673888 [40.6192789078s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 86683232 [40.8796899319s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 68349680 [1601.97090387s] called=0 cancelled=0 Broker.disconnectTimerFired()>
<DelayedCall 68349320 [41.9708168507s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 76923464 [41.8911337852s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 111910064 [42.3097207546s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 85198608 [42.4269149303s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 97684944 [3399.98493719s] called=0 cancelled=0 LoopingCall<3600>(CacheDirectoryManager.check, *(), **{})()>
<DelayedCall 78691000 [1602.43962884s] called=0 cancelled=0 Broker.disconnectTimerFired()>
<DelayedCall 55141656 [42.452218771s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 55211432 [3400.07495904s] called=0 cancelled=0 LoopingCall<3600>(CacheDirectoryManager.check, *(), **{})()>
<DelayedCall 118933552 [3400.03531289s] called=0 cancelled=0 LoopingCall<3600>(CacheDirectoryManager.check, *(), **{})()>
<DelayedCall 72142720 [3399.96432805s] called=0 cancelled=0 LoopingCall<3600>(CacheDirectoryManager.check, *(), **{})()>
<DelayedCall 76912904 [159.964112997s] called=0 cancelled=0 LeaseCheckingCrawler.start_slice()>
<DelayedCall 55141728 [1602.45180202s] called=0 cancelled=0 Broker.disconnectTimerFired()>
<DelayedCall 55210640 [160.074113131s] called=0 cancelled=0 LeaseCheckingCrawler.start_slice()>
<DelayedCall 86683304 [1600.87877703s] called=0 cancelled=0 Broker.disconnectTimerFired()>
<DelayedCall 78395440 [400.458470821s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 118934776 [100.029192209s] called=0 cancelled=0 BucketCountingCrawler.start_slice()>
<DelayedCall 96715984 [42.2768418789s] called=0 cancelled=0 Broker.keepaliveTimerFired()>
<DelayedCall 118934416 [160.02921319s] called=0 cancelled=0 LeaseCheckingCrawler.start_slice()>
<DelayedCall 97684512 [99.9835472107s] called=0 cancelled=0 BucketCountingCrawler.start_slice()>
<DelayedCall 91136584 [99.963588953s] called=0 cancelled=0 BucketCountingCrawler.start_slice()>
<DelayedCall 97684152 [159.983595133s] called=0 cancelled=0 LeaseCheckingCrawler.start_slice()>
<DelayedCall 102062488 [42.2725150585s] called=0 cancelled=0 TubConnector.connectionTimedOut()>
<DelayedCall 88673960 [1600.61787987s] called=0 cancelled=0 Broker.disconnectTimerFired()>
===============================================================================
[ERROR]: allmydata.test.test_immutable.Test.test_download_abort_if_too_many_corrupted_shares

Traceback (most recent call last):
Failure: twisted.trial.util.DirtyReactorAggregateError: Reactor was unclean.
Selectables:
<<class 'twisted.internet.tcp.Port'> of foolscap.pb.Listener on 43420>
<<class 'twisted.internet.tcp.Port'> of nevow.appserver.NevowSite on 51826>
<<class 'twisted.internet.tcp.Port'> of foolscap.pb.Listener on 50825>
<<class 'twisted.internet.tcp.Port'> of nevow.appserver.NevowSite on 34224>
<<class 'twisted.internet.tcp.Client'> to ('192.168.0.83', 43420) at 6799dd0>
<<class 'twisted.internet.tcp.TLSConnection'> to ('127.0.0.1', 54827) at 6b90410>
<<class 'twisted.internet.tcp.Port'> of foolscap.pb.Listener on 50059>
<<class 'twisted.internet.tcp.Port'> of foolscap.pb.Listener on 54827>
<<class 'twisted.internet.tcp.Port'> of foolscap.pb.Listener on 40795>
<<class 'twisted.internet.tcp.Port'> of nevow.appserver.NevowSite on 46756>
<<class 'twisted.internet.tcp.Port'> of foolscap.pb.Listener on 43414>
<Negotiation #0 on 50825>
<<class 'twisted.internet.tcp.TLSConnection'> to ('192.168.0.83', 43420) at 407fd10>
<<class 'twisted.internet.tcp.TLSConnection'> to ('192.168.0.83', 50825) at 4586290>
<<class 'twisted.internet.tcp.TLSConnection'> to ('127.0.0.1', 43420) at 407fe90>
<<class 'twisted.internet.tcp.TLSConnection'> to ('127.0.0.1', 40795) at 5ebce90>
<<class 'twisted.internet.tcp.TLSConnection'> to ('192.168.0.83', 43420) at 4da1e90>
<<class 'twisted.internet.tcp.TLSConnection'> to ('127.0.0.1', 43420) at 407f290>
<<class 'twisted.internet.tcp.TLSConnection'> to ('192.168.0.83', 43420) at 407f110>
<<class 'twisted.internet.tcp.TLSConnection'> to ('127.0.0.1', 43420) at 4da1d50>
<Negotiation #0 on 43420>
<<class 'twisted.internet.tcp.TLSConnection'> to ('192.168.0.83', 43420) at 4da1f90>
<<class 'twisted.internet.tcp.TLSConnection'> to ('127.0.0.1', 43420) at 3ff25d0>
<<class 'twisted.internet.tcp.TLSConnection'> to ('127.0.0.1', 40795) at 30d65d0>
<Negotiation #3 on 43420>
<Negotiation #4 on 43420>
<Negotiation #6 on 43420>
<Negotiation #7 on 43420>
<Negotiation #9 on 43420>
<Negotiation #10 on 43420>
<Negotiation #12 on 43420>
<Negotiation #13 on 43420>
<<class 'twisted.internet.tcp.TLSConnection'> to ('127.0.0.1', 43414) at 6799710>
<<class 'twisted.internet.tcp.TLSConnection'> to ('127.0.0.1', 43414) at 6799290>
<<class 'twisted.internet.tcp.TLSConnection'> to ('127.0.0.1', 43414) at 67997d0>
<Negotiation #0 on 54827>
<Negotiation #0 on 40795>
<Negotiation #2 on 40795>
<Negotiation #0 on 43414>
<Negotiation #2 on 43414>
<Negotiation #4 on 43414>
--8<---------------cut here---------------end--------------->8---

This is in a NixOS GNU/Linux x86_64 chroot.  I see the address
192.168.0.83 mentioned in the log, but it doesn’t have any chance of
being reachable in this setup (I couldn’t find where it originates
from).

Ideas?

Thanks,
Ludo’.

PS: For the record, the list of direct dependencies is:

    python-2.6.4
    setuptools-0.6c11
    python-zope-interface-3.3.0
    python-twisted-8.2.0
    python-setuptools-trial-0.5.3
    allmydata-tahoe-1.6.1.zip
    python-zbase32-1.1.1
    python-simplejson-2.0.9
    unzip-5.52
    python-argparse-0.9.1
    python-pyutil-1.3.30
    python-darcsver-1.3.1
    net-tools-1.60
    python-zfec-1.4.4
    sqlite-3.6.22
    python-pysqlite-2.5.5
    openssl-0.9.8l
    pyOpenSSL-0.8
    python-foolscap-0.4.2
    python-numpy-1.3.0
    python-nevow-0.9.33
    python-pycryptopp-0.5.15
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 197 bytes
Desc: not available
Url : http://allmydata.org/pipermail/tahoe-dev/attachments/20100301/b0c4f2fe/attachment.pgp

More information about the tahoe-dev mailing list