[Buildbot-devel] Scaling buildbot

[Dan Kegel]

I tried profiling the master (by passing --profiler=cprofile
--profile=/tmp/foo.log to twisted).

Here's the top page of results, sorted by cumtime.  You can see gitpoller.py in
there a bit.  I also clicked refresh a bunch of time on the waterfall;
when gitpoller was not active, that went quickly and cpu usage hit
350% for about five seconds,
but when gitpoller was active, it went very slowly and cpu usage barely
went over 100%.  So... maybe gitpoller is locking something the waterfall needs?

         80177368 function calls (79320621 primitive calls) in 2366.599 seconds

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000 2366.604 2366.604 base.py:1190(run)
        1    0.544    0.544 2364.265 2364.265 base.py:1195(mainLoop)
    76386    1.467    0.000 2165.843    0.028 epollreactor.py:352(doPoll)
    76386 1648.478    0.022 1648.480    0.022 {method 'poll' of
'select.epoll' objects}
45423/14520    1.665    0.000  592.939    0.041 defer.py:1051(_inlineCallbacks)
63491/31099    0.723    0.000  588.752    0.019 {method 'send' of
'generator' objects}
     5388    1.176    0.000  565.245    0.105 gitpoller.py:145(poll)
     3940    1.289    0.000  564.337    0.143 gitpoller.py:290(_dovccmd)
     3940    0.460    0.000  562.422    0.143
utils.py:163(getProcessOutputAndValue)
     3940    1.947    0.000  561.961    0.143
utils.py:21(_callProtocolWithDeferred)
     3940    1.203    0.000  559.611    0.142 posixbase.py:333(spawnProcess)
228851/59828    6.201    0.000  559.483    0.009 defer.py:500(_runCallbacks)
     3940    6.035    0.002  556.190    0.141 process.py:622(__init__)
108716/60087    0.423    0.000  550.586    0.009 defer.py:358(callback)
108720/60087    1.551    0.000  550.211    0.009
defer.py:471(_startRunCallbacks)
     3940    3.250    0.001  524.829    0.133 process.py:361(_fork)
     3940  521.345    0.132  521.345    0.132 {posix.fork}
    34806    1.143    0.000  516.253    0.015 log.py:75(callWithLogger)
    34806    1.035    0.000  515.070    0.015 log.py:70(callWithContext)
    34806    0.497    0.000  513.046    0.015 context.py:117(callWithContext)
    34806    0.747    0.000  512.525    0.015 context.py:61(callWithContext)
    34796    0.899    0.000  511.344    0.015 posixbase.py:572(_doReadOrWrite)
    11856    1.591    0.000  485.948    0.041
posixbase.py:242(_disconnectSelectable)
37700/13745    0.508    0.000  477.911    0.035 defer.py:1121(gotResult)
    11820    0.300    0.000  477.403    0.040
abstract.py:302(readConnectionLost)
    11820    0.892    0.000  474.194    0.040
process.py:902(childConnectionLost)
     7880    0.356    0.000  473.691    0.060 process.py:269(connectionLost)
15760/15427    1.330    0.000  469.848    0.030
process.py:913(maybeCallProcessEnded)
     3940    1.258    0.000  468.271    0.119
_baseprocess.py:51(maybeCallProcessEnded)
     3940    0.445    0.000  464.981    0.118 utils.py:153(processEnded)
23242/6870    0.605    0.000  301.586    0.044 defer.py:1201(unwindGenerator)
    76386    1.114    0.000  197.478    0.003 base.py:786(runUntilCurrent)
     2450    0.578    0.000  186.411    0.076 gitpoller.py:233(_process_changes)