On 30 Aralık 2009, 17:44, mk <mrk...@gmail.com> wrote:
> Hello everyone,
>
> I have figured out (sort of) how to do profiling of multithreaded
> programs with cProfile, it goes something like this:
>
> #!/usr/local/bin/python
>
> import cProfile
> import threading
>
> class TestProf(threading.Thread):
> def __init__(self, ip):
>
> threading.Thread.__init__(self)
> self.ip = ip
>
> def run(self):
> prof = cProfile.Profile()
> retval = prof.runcall(self.runmethod)
> prof.dump_stats('tprof' + self.ip)
>
> def runmethod(self):
> pass
>
> tp = TestProf('10.0.10.10')
>
> tp.start()
> tp.join()
>
> The problem is, now that I've done profiling in the actual program
> (profiled version here:http://python.domeny.com/cssh_profiled.py) with
> 9 threads and added up stats (using pstats.Stats.add()), the times I get
> are trivial:
>
> >>> p.strip_dirs().sort_stats('cumulative').print_stats(10)
> Wed Dec 30 16:23:59 2009 csshprof9.156.44.113
> Wed Dec 30 16:23:59 2009 csshprof9.156.46.243
> Wed Dec 30 16:23:59 2009 csshprof9.156.46.89
> Wed Dec 30 16:24:00 2009 csshprof9.156.47.125
> Wed Dec 30 16:24:00 2009 csshprof9.156.47.17
> Wed Dec 30 16:24:00 2009 csshprof9.156.47.29
> Wed Dec 30 16:24:01 2009 csshprof9.167.41.241
> Wed Dec 30 16:24:02 2009 csshprof9.168.119.15
> Wed Dec 30 16:24:02 2009 csshprof9.168.119.218
>
> 39123 function calls (38988 primitive calls) in 6.004 CPU seconds
>
> Ordered by: cumulative time
> List reduced from 224 to 10 due to restriction <10>
>
> ncalls tottime percall cumtime percall filename:lineno(function)
> 9 0.000 0.000 6.004 0.667 cssh.py:696(runmethod)
> 100 0.004 0.000 5.467 0.055 threading.py:389(wait)
> 82 0.025 0.000 5.460 0.067 threading.py:228(wait)
> 400 5.400 0.013 5.400 0.013 {time.sleep}
> 9 0.000 0.000 5.263 0.585 cssh.py:452(ssh_connect)
> 9 0.003 0.000 5.262 0.585 client.py:226(connect)
> 9 0.001 0.000 2.804 0.312
> transport.py:394(start_client)
> 9 0.005 0.001 2.254 0.250 client.py:391(_auth)
> 18 0.001 0.000 2.115 0.117
> transport.py:1169(auth_publickey)
> 18 0.001 0.000 2.030 0.113
> auth_handler.py:156(wait_for_response)
>
> <pstats.Stats instance at 0xb7ebde8c>
>
> It's not burning CPU time in the main thread (profiling with cProfile
> indicated smth similar to the above), it's not burning it in the
> individual worker threads - so where the heck it is burning this CPU
> time? bc 'top' shows heavy CPU load during most of the time of the
> program run.
>
> help...
>
> regards,
> mk
See http://code.google.com/p/yappi/ if you want to profile
multithreaded python app.
--
http://mail.python.org/mailman/listinfo/python-list
