[Buildbot-devel] Scaling buildbot

Pierre Tardy tardyp at gmail.com
Tue Jun 16 06:45:12 UTC 2015


I think you should use statprof within a manhole shell, while you are
exeriencing slowness.That is what I use, as it is pretty non intrusive, and
efficient.

Looking at your trace, it looks like indeed gitpoller is culprit.
It was not designed for running on more than a few repos.

Looks like the best option is to use gitlab webhooks


Le mar. 16 juin 2015 à 00:15, Dan Kegel <dank at kegel.com> a écrit :

> 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)
>
>
> ------------------------------------------------------------------------------
> _______________________________________________
> Buildbot-devel mailing list
> Buildbot-devel at lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/buildbot-devel
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://buildbot.net/pipermail/devel/attachments/20150616/ac48f574/attachment.html>


More information about the devel mailing list