[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