[Buildbot] #3081: buildbot.test.integration.test_try_client is flaky

Buildbot trac trac at buildbot.net
Fri Dec 26 13:49:15 UTC 2014


#3081: buildbot.test.integration.test_try_client is flaky
-------------------+-----------------------
Reporter:  Ben     |       Owner:  dustin
    Type:  defect  |      Status:  assigned
Priority:  major   |   Milestone:  0.9.0
 Version:  master  |  Resolution:
Keywords:          |
-------------------+-----------------------

Comment (by dustin):

 OK, another failure overnight (with just the tail of the tracebacks this
 time):
 {{{
 2014-12-25 21:15:25+0000 [-] -->
 buildbot.test.integration.test_master.RunMaster.test_master1 <--
 2014-12-25 21:15:26+0000 [-] Loading configuration from
 '/home/ubuntu/buildbot/_trial_temp/basdir/master.cfg'
 2014-12-25 21:15:26+0000 [-] Setting up database with URL
 'sqlite:/state.sqlite'
 2014-12-25 21:15:26+0000 [-] setting database journal mode to 'wal'
 2014-12-25 21:15:26+0000 [-] using SQLAlchemy-Migrate version 0.7.2
 2014-12-25 21:15:26+0000 [-] Initializing empty database
 2014-12-25 21:15:29+0000 [-] Starting BuildMaster -- buildbot.version:
 0.9.0
 2014-12-25 21:15:29+0000 [-] Loading configuration from
 '/home/ubuntu/buildbot/_trial_temp/basdir/master.cfg'
 2014-12-25 21:15:29+0000 [-] adding 1 new changesources, removing 0
 2014-12-25 21:15:29+0000 [-] <buildbot.changes.pb.PBChangeSource object at
 0x7f0e93202d90>.startService
 2014-12-25 21:15:29+0000 [-] <buildbot.changes.pb.PBChangeSource object at
 0x7f0e93202d90>._startActivityPolling
 2014-12-25 21:15:29+0000 [-] <buildbot.changes.pb.PBChangeSource object at
 0x7f0e93202d90>.startService return
 2014-12-25 21:15:30+0000 [-] adding 1 new builders, removing 0
 2014-12-25 21:15:30+0000 [-] trying to load status pickle from
 /home/ubuntu/buildbot/_trial_temp/basdir/testy/builder
 2014-12-25 21:15:30+0000 [-] no saved status pickle, creating a new one
 2014-12-25 21:15:30+0000 [-] added builder testy with tags []
 2014-12-25 21:15:30+0000 [-] adding scheduler 'all'
 2014-12-25 21:15:30+0000 [-] <buildbot.schedulers.basic.AnyBranchScheduler
 object at 0x7f0e93202e90>.startService
 2014-12-25 21:15:30+0000 [-] <buildbot.schedulers.basic.AnyBranchScheduler
 object at 0x7f0e93202e90>._startActivityPolling
 2014-12-25 21:15:30+0000 [-] <buildbot.schedulers.basic.AnyBranchScheduler
 object at 0x7f0e93202e90>.startService return
 2014-12-25 21:15:30+0000 [-] adding scheduler 'force'
 2014-12-25 21:15:30+0000 [-]
 <buildbot.schedulers.forcesched.ForceScheduler object at
 0x7f0e93202f90>.startService
 2014-12-25 21:15:30+0000 [-]
 <buildbot.schedulers.forcesched.ForceScheduler object at
 0x7f0e93202f90>._startActivityPolling
 2014-12-25 21:15:30+0000 [-]
 <buildbot.schedulers.forcesched.ForceScheduler object at
 0x7f0e93202f90>.startService return
 2014-12-25 21:15:30+0000 [-] No web server configured on this master
 2014-12-25 21:15:30+0000 [-] adding 1 new slaves, removing 0
           File
 "/home/ubuntu/buildbot/master/buildbot/buildslave/protocols/pb.py", line
 49, in updateRegistration
             portStr, username, password, self._getPerspective)
           File "/home/ubuntu/buildbot/master/buildbot/pbmanager.py", line
 58, in register
             disp = self.dispatchers[portstr] = Dispatcher(portstr)
           File "/home/ubuntu/buildbot/master/buildbot/pbmanager.py", line
 124, in __init__
             self.port = strports.listen(portstr, self.serverFactory)
           File "/home/ubuntu/buildbot/sandbox/local/lib/python2.7/site-
 packages/twisted/application/strports.py", line 99, in listen
             return getattr(reactor, 'listen'+name)(*args, **kw)
           File "/home/ubuntu/buildbot/sandbox/local/lib/python2.7/site-
 packages/twisted/internet/posixbase.py", line 495, in listenTCP
             p.startListening()
           File "/home/ubuntu/buildbot/sandbox/local/lib/python2.7/site-
 packages/twisted/internet/tcp.py", line 993, in startListening
 log.msg(''.join(traceback.format_list(traceback.extract_stack())))

 2014-12-25 21:15:30+0000 [-] PBServerFactory starting on 32820
 2014-12-25 21:15:30+0000 [-] Starting factory
 <twisted.spread.pb.PBServerFactory instance at 0x7f0e910c7200>
 2014-12-25 21:15:30+0000 [-] _activityPollCall.start returned
 2014-12-25 21:15:30+0000 [-] BuildMaster is running
 2014-12-25 21:15:30+0000 [-]
 <buildbot.schedulers.forcesched.ForceScheduler object at
 0x7f0e93202f90>.stopService
 2014-12-25 21:15:30+0000 [-] <buildbot.schedulers.basic.AnyBranchScheduler
 object at 0x7f0e93202e90>.stopService
 2014-12-25 21:15:30+0000 [-] <buildbot.changes.pb.PBChangeSource object at
 0x7f0e93202d90>.stopService
 2014-12-25 21:15:30+0000 [-] (TCP Port 32820 Closed)
 2014-12-25 21:15:30+0000 [-] Stopping factory
 <twisted.spread.pb.PBServerFactory instance at 0x7f0e910c7200>
           File "/home/ubuntu/buildbot/master/buildbot/util/service.py",
 line 185, in _activityPoll
             yield self.activate()
           File "/home/ubuntu/buildbot/master/buildbot/changes/pb.py", line
 152, in activate
             self._register(port)
           File "/home/ubuntu/buildbot/master/buildbot/changes/pb.py", line
 164, in _register
             self.getPerspective)
           File "/home/ubuntu/buildbot/master/buildbot/pbmanager.py", line
 58, in register
             disp = self.dispatchers[portstr] = Dispatcher(portstr)
           File "/home/ubuntu/buildbot/master/buildbot/pbmanager.py", line
 124, in __init__
             self.port = strports.listen(portstr, self.serverFactory)
           File "/home/ubuntu/buildbot/sandbox/local/lib/python2.7/site-
 packages/twisted/application/strports.py", line 99, in listen
             return getattr(reactor, 'listen'+name)(*args, **kw)
           File "/home/ubuntu/buildbot/sandbox/local/lib/python2.7/site-
 packages/twisted/internet/posixbase.py", line 495, in listenTCP
             p.startListening()
           File "/home/ubuntu/buildbot/sandbox/local/lib/python2.7/site-
 packages/twisted/internet/tcp.py", line 993, in startListening
 log.msg(''.join(traceback.format_list(traceback.extract_stack())))

 2014-12-25 21:15:31+0000 [-] PBServerFactory starting on 33392
 2014-12-25 21:15:31+0000 [-] Starting factory
 <twisted.spread.pb.PBServerFactory instance at 0x7f0e83ff5050>
 2014-12-25 21:15:31+0000 [-] _activityPollCall.start returned
 2014-12-25 21:15:31+0000 [-] <buildbot.changes.pb.PBChangeSource object at
 0x7f0e93202d90>.stopService return
 2014-12-25 21:15:31+0000 [-]
 <buildbot.schedulers.forcesched.ForceScheduler object at
 0x7f0e93202f90>.stopService return
 2014-12-25 21:15:31+0000 [-] _activityPollCall.start returned
 2014-12-25 21:15:31+0000 [-] <buildbot.schedulers.basic.AnyBranchScheduler
 object at 0x7f0e93202e90>.stopService return
 2014-12-25 21:15:31+0000 [-] BuildMaster is stopped
 2014-12-25 21:15:31+0000 [-] Main loop terminated.
 }}}

 Running with this diff:

 {{{
 #!patch
 diff --git a/master/buildbot/util/service.py
 b/master/buildbot/util/service.py
 index 3068413..d16a5f6 100644
 --- a/master/buildbot/util/service.py
 +++ b/master/buildbot/util/service.py
 @@ -100,10 +100,13 @@ class ClusteredService(service.Service,
 util.ComparableMixin):
          # subclasses should override startService only to perform actions
 that should
          # run on all instances, even if they never get activated on this
 master.

 +        log.msg('%s.startService' % self)
          service.Service.startService(self)
          self._startActivityPolling()
 +        log.msg('%s.startService return' % self)

      def stopService(self):
 +        log.msg('%s.stopService' % self)
          # subclasses should override stopService only to perform actions
 that should
          # run on all instances, even if they never get activated on this
 master.

 @@ -129,9 +132,13 @@ class ClusteredService(service.Service,
 util.ComparableMixin):
                  return d

          d.addCallback(lambda _: service.Service.stopService(self))
 +       @d.addCallback
 +       def msg(_):
 +               log.msg('%s.stopService return' % self)
          return d

      def _startActivityPolling(self):
 +        log.msg('%s._startActivityPolling' % self)
          self._activityPollCall = task.LoopingCall(self._activityPoll)
          # plug in a clock if we have one, for tests
          if hasattr(self, 'clock'):
 @@ -140,6 +147,11 @@ class ClusteredService(service.Service,
 util.ComparableMixin):
          d = self._activityPollCall.start(self.POLL_INTERVAL_SEC,
 now=True)
          self._activityPollDeferred = d

 +       @d.addBoth
 +       def ret(x):
 +               log.msg('_activityPollCall.start returned')
 +               return x
 +
          # this should never happen, but just in case:
          d.addErrback(log.err, 'while polling for service activity:')

 }}}

--
Ticket URL: <http://trac.buildbot.net/ticket/3081#comment:11>
Buildbot <http://buildbot.net/>
Buildbot: build/test automation


More information about the bugs mailing list