[Buildbot-devel] Scaling buildbot

Dan Kegel dank at kegel.com
Mon Jun 15 22:13:31 UTC 2015


FWIW, here's a longer profile run:
         451294849 function calls (445499425 primitive calls) in
258337.448 seconds

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000 258339.441 258339.441 base.py:1190(run)
        1  128.364  128.364 258337.042 258337.042 base.py:1195(mainLoop)
  7797767  120.268    0.000 248912.356    0.032 epollreactor.py:352(doPoll)
  7797767 209133.001    0.027 209133.004    0.027 {method 'poll' of
'select.epoll' objects}
1269409/670493  153.257    0.000 45949.182    0.069
defer.py:1051(_inlineCallbacks)
1356738/981344   64.811    0.000 45677.147    0.047 {method 'send' of
'generator' objects}
   642008  112.770    0.000 45326.403    0.071 gitpoller.py:145(poll)
   466446  143.065    0.000 44986.667    0.096 gitpoller.py:290(_dovccmd)
   466446   51.808    0.000 44777.164    0.096
utils.py:163(getProcessOutputAndValue)
   466446  174.606    0.000 44725.356    0.096
utils.py:21(_callProtocolWithDeferred)
   466446  106.746    0.000 44515.983    0.095 posixbase.py:333(spawnProcess)
   466446  602.606    0.001 44310.619    0.095 process.py:622(__init__)
   466446  251.277    0.001 42475.513    0.091 process.py:361(_fork)
   466446 42205.382    0.090 42205.382    0.090 {posix.fork}
  2189741  109.833    0.000 39657.423    0.018 log.py:75(callWithLogger)
  2189741  103.580    0.000 39542.368    0.018 log.py:70(callWithContext)
  2189741   52.154    0.000 39344.057    0.018 context.py:117(callWithContext)
  2189741   65.371    0.000 39290.716    0.018 context.py:61(callWithContext)
  2189730   84.952    0.000 39216.486    0.018 posixbase.py:572(_doReadOrWrite)
  1399426  101.722    0.000 38678.609    0.028
posixbase.py:242(_disconnectSelectable)
  1399338   29.503    0.000 38360.472    0.027
abstract.py:302(readConnectionLost)
   932892   29.718    0.000 38216.460    0.041 process.py:269(connectionLost)
  1399338   50.151    0.000 38213.456    0.027
process.py:902(childConnectionLost)
1865784/1494651  139.332    0.000 38102.361    0.025
process.py:913(maybeCallProcessEnded)
1736540/1156383   26.442    0.000 37754.802    0.033 defer.py:358(callback)
1736696/1156386   99.156    0.000 37733.184    0.033
defer.py:471(_startRunCallbacks)
   466446  106.154    0.000 37689.942    0.081
_baseprocess.py:51(maybeCallProcessEnded)
2990283/2170486  185.136    0.000 37685.491    0.017 defer.py:500(_runCallbacks)
   466446   33.564    0.000 37548.595    0.080 utils.py:153(processEnded)
927281/586647   39.292    0.000 37451.099    0.064 defer.py:1121(gotResult)
   863624   47.978    0.000 25821.239    0.030 process.py:285(reapProcess)
466446/466425   43.695    0.000 25676.446    0.055
_baseprocess.py:40(processEnded)
413617/337609   37.707    0.000 22825.025    0.068
defer.py:1201(unwindGenerator)
   290606   56.227    0.000 14346.864    0.049
gitpoller.py:233(_process_changes)

On Fri, Jun 12, 2015 at 3:30 PM, Dan Kegel <dank at kegel.com> wrote:
> 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)




More information about the devel mailing list