[tahoe-dev] profiling part 2: what goes on in the Python interpreter during uploading

[zooko]

Folks:

I uploaded ten files in sequence, each file containing 1 mebibyte of  
random data.  The hotshot profiler reported this afterward.

This shows that it took about 330 seconds to do the upload, and that  
the part of our code that took the most time was the logging, which  
used less than 3% of the total time.  (I guess this might be due it  
occasionally blocking for disk writes rather than it actually being  
CPU-intensive.)

So as far as this test shows, I'm happy with how lightweight a tahoe  
node is on the CPU during uploading.

Regards,

Zooko

          825428 function calls (801014 primitive calls) in 339.972  
CPU seconds

    Ordered by: cumulative time
    List reduced from 1198 to 20 due to restriction <20>

    ncalls  tottime  percall  cumtime  percall filename:lineno(function)
         1    0.000    0.000  339.972  339.972 posixbase.py:219(run)
         1    0.103    0.103  339.972  339.972 posixbase.py:223 
(mainLoop)
     10153  329.236    0.032  339.099    0.033 selectreactor.py:95 
(doSelect)
     10464    0.150    0.000    9.488    0.001 log.py:38(callWithLogger)
10499/10477    0.138    0.000    9.325    0.001 log.py:33 
(callWithContext)
10499/10477    0.054    0.000    8.990    0.001 context.py:58 
(callWithContext)
10499/10477    0.103    0.000    8.928    0.001 context.py:32 
(callWithContext)
     10464    0.087    0.000    8.823    0.001 selectreactor.py:146 
(_doReadOrWrite)
      1057    0.236    0.000    5.055    0.005 tcp.py:345(doRead)
       851    0.024    0.000    4.882    0.006 tcp.py:120(doRead)
       876    0.017    0.000    4.629    0.005 banana.py:623 
(dataReceived)
       876    0.197    0.000    4.611    0.005 banana.py:691(handleData)
13778/5622    0.171    0.000    4.528    0.001 defer.py:306 
(_runCallbacks)
11566/3767    0.039    0.000    4.354    0.001 defer.py:168 
(addCallbacks)
6454/3999    0.029    0.000    4.286    0.001 defer.py:229(callback)
6464/3999    0.023    0.000    4.280    0.001 defer.py:283 
(_startRunCallbacks)
      2811    0.030    0.000    4.124    0.001 banana.py:1044 
(handleClose)
      1164    0.016    0.000    4.006    0.003 call.py:614(receiveClose)
1709/1449    0.003    0.000    3.874    0.003 defer.py:279(_continue)
1709/1449    0.100    0.000    3.871    0.003 defer.py:270(unpause)