How to calculate the average result of several cProfile results?

Question

Instead of only running the profile one time like this:

import cProfile

def do_heavy_lifting():
    for i in range(100):
        print('hello')

profiller = cProfile.Profile()
profiller.enable()

do_heavy_lifting()

profiller.disable()
profiller.print_stats(sort='time')

Where the profile results are like this:

      502 function calls in 0.000 seconds

Ordered by: internal time

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
   100    0.000    0.000    0.000    0.000 {built-in method builtins.print}
   200    0.000    0.000    0.000    0.000 cp1252.py:18(encode)
   200    0.000    0.000    0.000    0.000 {built-in method _codecs.charmap_encode}
     1    0.000    0.000    0.000    0.000 test.py:2(do_heavy_lifting)
     1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

I would like to run several times and print the average results, for better precision.

This is a initial script recipe I thought of:

import cProfile

def do_heavy_lifting():
    for i in range(100):
        print('hello')

def best_of_profillings(target_profile_function, count):
    profile_results = []

    for index in range(count):
        profiller = cProfile.Profile()
        profiller.enable()

        target_profile_function()

        profiller.disable()
        profile_results.append(profiller)

    profile_results /= count
    return profile_results

heavy_lifting_result = best_of_profillings(do_heavy_lifting, 10)
heavy_lifting_result.print_stats(sort='time')

After running this, it should display the results like its first version did, but the difference is that they are the average of several runs, instead of running it one time.

The draft script still missing the part profile_results /= count where after all the iterations, I would get all the computed results and create the average results and display it on the screen always:

      502 function calls in 0.000 seconds

Ordered by: internal time

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
   100    0.000    0.000    0.000    0.000 {built-in method builtins.print}
   200    0.000    0.000    0.000    0.000 cp1252.py:18(encode)
   200    0.000    0.000    0.000    0.000 {built-in method _codecs.charmap_encode}
     1    0.000    0.000    0.000    0.000 test.py:2(do_heavy_lifting)
     1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

why don't you just run `do_heavy_lifting()` multiple times? – sam46 Jan 26 '19 at 03:48 — sam46, Jan 26 '19 at 03:48

score 3 · Accepted Answer · answered Jan 26 '19 at 04:18

I managed to create the following code, with the function average(). I opened the implementation of pstats and observed there is a function called Stats.add() which seems to just concatenate results into the current object: https://docs.python.org/3.7/library/profile.html#pstats.Stats.add

import io
import pstats
import cProfile

def do_heavy_lifting():
    for i in range(100):
        print('hello')

def average(stats, count):
    stats.total_calls /= count
    stats.prim_calls /= count
    stats.total_tt /= count

    for func, source in stats.stats.items():
        cc, nc, tt, ct, callers = source
        stats.stats[func] = ( cc/count, nc/count, tt/count, ct/count, callers )

    return stats

def best_of_profillings(target_profile_function, count):
    output_stream = io.StringIO()
    profiller_status = pstats.Stats( stream=output_stream )

    for index in range(count):
        profiller = cProfile.Profile()
        profiller.enable()

        target_profile_function()

        profiller.disable()
        profiller_status.add( profiller )

        print( 'Profiled', '%.3f' % profiller_status.total_tt, 'seconds at', index,
                'for', target_profile_function.__name__, flush=True )

    average( profiller_status, count )
    profiller_status.sort_stats( "time" )
    profiller_status.print_stats()

    return "\nProfile results for %s\n%s" % ( 
           target_profile_function.__name__, output_stream.getvalue() )

heavy_lifting_result = best_of_profillings( do_heavy_lifting, 10 )
print( heavy_lifting_result )

Results:

Profile results for do_heavy_lifting
         102.0 function calls in 0.001 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    100.0    0.001    0.000    0.001    0.000 {built-in method builtins.print}
      1.0    0.000    0.000    0.001    0.001 D:\test.py:5(do_heavy_lifting)
      1.0    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

How to calculate the average result of several cProfile results?

1 Answers1

Linked