Some perf related changes when profiling the MI Task example within spiff-arena

[jbirddog]

When looking at the time spent executing the MI Tasks example with 50 iterations in spiff-arena (not including any backend db related operations) these appeared to be first low hanging fruit. These changes result in ~1.2 million less function calls and ~43% runtime improvement for the example process.

Some timings:

Before:

         2953142 function calls (2906781 primitive calls) in 8.029 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    10476    0.335    0.000    9.500    0.001 task.py:209(__next__)
      314    0.006    0.000    9.432    0.030 workflow_execution_service.py:195(get_ready_engine_steps)
      316    0.011    0.000    8.359    0.026 workflow.py:95(get_tasks)
      2/1    0.000    0.000    7.886    7.886 workflow_execution_service.py:461(run_and_save)
      2/1    0.001    0.001    7.779    7.779 workflow_execution_service.py:141(spiff_run)
      315    0.006    0.000    6.190    0.020 workflow.py:187(refresh_waiting_tasks)
    75464    0.976    0.000    4.857    0.000 task.py:50(_next)
     8353    0.042    0.000    2.158    0.000 workflow.py:69(is_completed)
    74582    0.332    0.000    2.112    0.000 task.py:30(matches)
      315    0.013    0.000    1.949    0.006 workflow.py:101(get_active_subprocesses)
   128397    0.522    0.000    1.717    0.000 task.py:150(matches)
339515/338281    0.785    0.000    1.704    0.000 {method 'get' of 'dict' objects}
11806/8420    0.043    0.000    1.596    0.000 {built-in method builtins.next}
     3870    0.042    0.000    1.523    0.000 _reloader.py:40(_iter_module_paths)
    62082    0.591    0.000    1.482    0.000 task.py:215(_next)
  363/313    0.004    0.000    1.267    0.004 task.py:333(run)
   109396    0.297    0.000    1.114    0.000 task.py:120(children)
  363/313    0.002    0.000    1.027    0.003 task.py:373(complete)
  363/313    0.003    0.000    1.013    0.003 base.py:355(_on_complete)
   243699    0.602    0.000    0.910    0.000 uuid.py:268(__hash__)
41198/514    0.277    0.000    0.671    0.001 copy.py:118(deepcopy)
    11051    0.099    0.000    0.649    0.000 task.py:251(_handle_leaf_depth)
  312/261    0.002    0.000    0.647    0.002 base.py:252(_update)

After:

         1691462 function calls (1649648 primitive calls) in 4.603 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
      2/1    0.001    0.000    4.158    4.158 workflow_execution_service.py:463(run_and_save)
        1    0.000    0.000    3.848    3.848 process_instance_processor.py:1105(save)
        1    0.000    0.000    3.848    3.848 scoping.py:558(commit)
        1    0.000    0.000    3.823    3.823 query.py:2650(all)
     1936    0.049    0.000    3.475    0.002 _reloader.py:40(_iter_module_paths)
        2    0.001    0.000    3.002    1.501 query.py:2821(_iter)
      314    0.003    0.000    2.730    0.009 workflow_execution_service.py:195(get_ready_engine_steps)
    75464    0.652    0.000    2.680    0.000 task.py:55(_next)
     2674    0.159    0.000    2.357    0.001 task.py:220(__next__)
      316    0.009    0.000    2.195    0.007 workflow.py:99(get_tasks)
298149/298147    0.667    0.000    1.429    0.000 {method 'get' of 'dict' objects}
        2    0.000    0.000    1.198    0.599 session.py:2245(execute)
  363/313    0.004    0.000    1.077    0.003 task.py:333(run)
       84    0.005    0.000    0.919    0.011 <frozen os>:282(walk)
  363/313    0.002    0.000    0.893    0.003 task.py:373(complete)
  363/313    0.003    0.000    0.871    0.003 base.py:355(_on_complete)
      2/1    0.002    0.001    0.764    0.764 workflow_execution_service.py:141(spiff_run)
   204365    0.503    0.000    0.761    0.000 uuid.py:268(__hash__)
     1943    0.038    0.000    0.747    0.000 <frozen genericpath>:27(isfile)
    70372    0.193    0.000    0.657    0.000 task.py:120(children)
41197/513    0.275    0.000    0.650    0.001 copy.py:118(deepcopy)
      315    0.005    0.000    0.641    0.002 workflow.py:187(refresh_waiting_tasks)
    10951    0.097    0.000    0.626    0.000 task.py:261(_handle_leaf_depth)
      463    0.011    0.000    0.623    0.001 copy.py:217(_deepcopy_dict)
  312/261    0.002    0.000    0.610    0.002 base.py:252(_update)

The len changes came from profiling the total number of calls.

Before:

         2035632 function calls (1993141 primitive calls) in 5.636 seconds

   Ordered by: call count

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
300135/299729    0.688    0.000    1.465    0.000 {method 'get' of 'dict' objects}
   204376    0.260    0.000    0.260    0.000 {built-in method builtins.hash}
   204365    0.509    0.000    0.770    0.000 uuid.py:268(__hash__)
188496/188492    0.241    0.000    0.241    0.000 {built-in method builtins.len}
   164712    0.204    0.000    0.349    0.000 task.py:92(state)
    84586    0.214    0.000    0.464    0.000 task.py:139(has_state)
    81705    0.111    0.000    0.111    0.000 {method 'pop' of 'list' objects}
    81471    0.211    0.000    0.665    0.000 task.py:150(matches)
    75464    0.876    0.000    3.328    0.000 task.py:55(_next)
    74582    0.224    0.000    0.852    0.000 task.py:30(matches)

After:

         1756864 function calls (1714280 primitive calls) in 4.770 seconds

   Ordered by: call count

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
299274/298690    0.667    0.000    1.432    0.000 {method 'get' of 'dict' objects}
   204375    0.258    0.000    0.258    0.000 {built-in method builtins.hash}
   204365    0.502    0.000    0.759    0.000 uuid.py:268(__hash__)
    84586    0.107    0.000    0.107    0.000 task.py:139(has_state)
    81626    0.110    0.000    0.110    0.000 {method 'pop' of 'list' objects}
    81471    0.209    0.000    0.312    0.000 task.py:150(matches)
    80126    0.099    0.000    0.099    0.000 task.py:92(state)
    75464    0.649    0.000    2.790    0.000 task.py:55(_next)
    74582    0.221    0.000    0.519    0.000 task.py:30(matches)