Profile: Interpret output

[Rune Hansen]

Hello, I was wondering if some of you could be persuaded into explaining how 
to read and interpret the output from profile and pstats.
I've written a threaded server that initially starts a db connection thread 
and a heartbeat thread. When a client connects it's handled by a separate 
thread, one for each client. In addition a kill-thread with a timeout of 10 
seconds is started to terminate clients failing identification. Running the 
server with pstats and profile gives this result:

Thu Feb  6 14:57:52 2003    profile_results

         958 function calls in 0.110 CPU seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.110    0.110 <string>:1(?)
        1    0.000    0.000    0.110    0.110 profile:0(start())
        1    0.000    0.000    0.110    0.110 Server18.py:900(ServerStart)
        1    0.000    0.000    0.110    0.110 Server18.py:912(start)
        1    0.000    0.000    0.100    0.100 Server18.py:594(__init__)
        1    0.010    0.010    0.080    0.080 Server18.py:633(readFavicons)
      266    0.030    0.000    0.030    0.000 
//usr/lib/python2.2/base64.py:34(encodestring)
        1    0.000    0.000    0.020    0.020 Server18.py:532(__init__)
      266    0.010    0.000    0.020    0.000 
/usr/lib/python2.2/site-packages/MySQLdb/cursors.py:254(fetchone)
        1    0.000    0.000    0.020    0.020 Server18.py:618(startDbThread)
        1    0.000    0.000    0.020    0.020 
/usr/lib/python2.2/site-packages/MySQLdb/cursors.py:97(_execute)
        1    0.000    0.000    0.020    0.020 
/usr/lib/python2.2/site-packages/MySQLdb/cursors.py:80(execute)
        1    0.000    0.000    0.020    0.020 
/usr/lib/python2.2/site-packages/MySQLdb/cursors.py:248(_query)
        6    0.000    0.000    0.020    0.003 
//usr/lib/python2.2/threading.py:353(__init__)
        1    0.000    0.000    0.010    0.010 
/usr/lib/python2.2/site-packages/MySQLdb/cursors.py:166(__do_query)
        2    0.000    0.000    0.010    0.005 Server18.py:891(Conn)
        6    0.010    0.002    0.010    0.002 
//usr/lib/python2.2/threading.py:336(_newname)
        2    0.010    0.005    0.010    0.005 
/usr/lib/python2.2/site-packages/MySQLdb/connections.py:40(_make_connection)
        2    0.000    0.000    0.010    0.005 
/usr/lib/python2.2/site-packages/MySQLdb/__init__.py:60(Connect)
      267    0.010    0.000    0.010    0.000 
/usr/lib/python2.2/site-packages/MySQLdb/cursors.py:51(_check_executed)
        2    0.000    0.000    0.010    0.005 
/usr/lib/python2.2/site-packages/MySQLdb/connections.py:91(__init__)
        1    0.010    0.010    0.010    0.010 
/usr/lib/python2.2/site-packages/MySQLdb/cursors.py:241(_get_result)
        1    0.010    0.010    0.010    0.010 
/usr/lib/python2.2/site-packages/MySQLdb/cursors.py:198(_fetch_row)
        4    0.000    0.000    0.010    0.002 
//usr/lib/python2.2/SocketServer.py:464(process_request)
        5    0.000    0.000    0.010    0.002 
//usr/lib/python2.2/SocketServer.py:213(handle_request)
        6    0.010    0.002    0.010    0.002 
//usr/lib/python2.2/threading.py:367(_set_daemon)
        [snip: I've removed all lines with NULL cumtime]

Now, this doesn't make sense to me cause I know that the servers parsing of 
a SOAP packet returned from Google does take some time. This happens inside 
a client thread and it seems as though profile doesn't catch on to it. So 
maybe I should extend my question to include "how to I preform profile on 
multi-threaded servers..."?

regards

/rune