multithreading, performance, again...

Discussion in 'Python' started by mk, Dec 30, 2009.

  1. mk

    mk Guest

    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
     
    mk, Dec 30, 2009
    #1
    1. Advertising

  2. mk

    Oktaka Com Guest

    On 30 Aralık 2009, 17:44, mk <> 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.
     
    Oktaka Com, Jan 18, 2010
    #2
    1. Advertising

Want to reply to this thread or ask your own question?

It takes just 2 minutes to sign up (and it's free!). Just click the sign up button to choose a username and then you can ask your own questions on the forum.
Similar Threads
  1. amit
    Replies:
    0
    Views:
    398
  2. che
    Replies:
    2
    Views:
    509
  3. abcd

    Importing again and again

    abcd, Jun 8, 2006, in forum: Python
    Replies:
    9
    Views:
    334
    Maric Michaud
    Jun 9, 2006
  4. bugbear
    Replies:
    4
    Views:
    2,911
    Arne Vajhøj
    Mar 28, 2008
  5. Replies:
    16
    Views:
    517
Loading...

Share This Page