solent-eng / solent

Free software sequencer architecture
GNU Lesser General Public License v3.0
7 stars 4 forks source link

Profile and pursue any easy wins #62

Closed cratuki closed 7 years ago

cratuki commented 7 years ago

Until now there has been no deliberate profiling of solent. Will be giving a demo this week, and am wondering whether I can quickly improve the throughput. Have a shot.

cratuki commented 7 years ago

Quick profile shows that my use of "dir" in the engine is causing significant overhead. Going to have a look at what would be involved in factoring that out.

cratuki commented 7 years ago

More info on the profiling. Have written a profiling class, solent.scenarios.profile_event_loop

Line with dir performance: 300020 2.689 0.000 2.689 0.000 {built-in method dir}

Reckon I can refactor engine to never use dir during the event loop.

cratuki commented 7 years ago

Significant improvement. Event-loop overhead is now about a third of what it was before this one change.

// // before

     2401769 function calls (2401752 primitive calls) in 4.906 seconds

Ordered by: internal time

ncalls tottime percall cumtime percall filename:lineno(function) 300020 2.684 0.000 2.684 0.000 {built-in method dir} 100001 0.523 0.000 4.836 0.000 engine.py:188(turn) 100001 0.409 0.000 3.611 0.000 orb.py:165(eng_turn) 100000 0.268 0.000 0.290 0.000 activity.py:32(mark) 200015 0.173 0.000 0.254 0.000 _collections_abc.py:517(iter)

// // after

     2301881 function calls (2301864 primitive calls) in 1.746 seconds

Ordered by: internal time

ncalls tottime percall cumtime percall filename:lineno(function) 100001 0.439 0.000 1.687 0.000 engine.py:188(turn) 100000 0.223 0.000 0.242 0.000 activity.py:32(mark) 100001 0.198 0.000 0.651 0.000 orb.py:187(eng_turn) 200015 0.142 0.000 0.209 0.000 _collections_abc.py:517(iter) 100000 0.092 0.000 0.389 0.000 profile_event_loop.py:67(orb_turn)

petr-tik commented 7 years ago

Can you show the profiling tools/script as well?

cratuki commented 7 years ago

Here is the block,

import cProfile

...

def main():
    pr = cProfile.Profile()
    pr.enable()
    #
    try:
        app()
    except KeyboardInterrupt:
        pass
    except SolentQuitException:
        pass
    #
    pr.disable()
    pr.print_stats(
        sort='time')

I'm running a commit now. When I have, you can see the profile usage in solent.scenarios.profile_event_loop.

cratuki commented 7 years ago

Pushed.

Would you like to do a code review? :) Branch is cturner.20170506

cratuki commented 7 years ago

Oh, I'll create a pull request first

cratuki commented 7 years ago

Here: https://github.com/solent-eng/solent/pull/64

cratuki commented 7 years ago

Replaced by https://github.com/solent-eng/solent/pull/65

cratuki commented 7 years ago

I'm impatient today and want to move on, so going to square and merge this myself.

cratuki commented 7 years ago

Have been happy with these changes. Closing.