Profiling of objects in Python 3



  • @a_block Sorry for my ignorance, I had no output before just errors and then I didn't check old time.clock() anymore so I thought time.clock() does not work at all.

    The numbers I get with the new time.process_time() are strange and every other is 0.

    anyway got it working with the old time.clock()

    this works for now, but a error free console would be nice in the future ...
    or perhaps I can get my head around that decorator profilling from zipit ...
    still a little to much for me.

    If somebody feels generous perhaps post a decorator version of

    import cProfile, math, pstats, c4d
    
    def some_function():
        profile = cProfile.Profile()
    
        # Start of profiling
        profile.enable()
        data = [math.sqrt(abs(math.sin(i * .001) * math.cos(i * .001)))
                for i in range(100000)]
        profile.disable()
        # End of profiling
    
        stats = pstats.Stats(profile)
        stats.strip_dirs()
        stats.sort_stats("cumtime")
        stats.print_stats()
    
    if __name__ == "__main__":
        c4d.CallCommand(13957) # Konsole löschen / delete console log
        some_function()
    

    anyway thanks



  • ???
    So, what are the errors?
    I have none...



  • Hi,

    your code is not faulty, at least not in a strict sense. The problem is that you did choose time.time() for the profiling, which is not a reliable tick source in any version of Python. You can use it if you are only interested in timings above the 100 ms mark. For everything else you should cProfile. The code below demonstrates the difference and also goes a bit into the details. The bottom line is (at least from my point of view) that you cannot do what you want to do in any language, especially on Windows.

    You might have to run the code a few times, because unreliability also means that it can work when you don't want it to ;).

    Cheers,
    Ferdinand

    #!py3
    
    """Simple example for a profiling decorator.
    
    Okay, here are three problems at play.
    
        1. The accuracy of the high precision system clock depends on the OS,
           with Windows usually being said to be substantially worse than
           MacOS and Linux (this ranking should be taken with a grain of salt).
        2. time.time() is not very precise in general, it has been considered
           for depreciation in 3.X but still "lingers" for some reason unknown
           to me.
        3. Meaningful profiling, i.e. the measuring of timings, is in general a
           complicated thing, when it goes below the 10-20 ms mark. This is not
           just a Python thing, but basically applies to anything that runs on
           a complex OS.
    
    Technical Solutions:
    
    time.time() is in general a bad choice for timings unless you want to 
    measure timings in the smaller than 100 ms range.
    
    There are some "tips" out there which recommend to use something like 
    time.perf_counter_ns() or time.process_time() instead. Which does not make
    much sense to me since these are the clocks time.time() is choosing from
    when looking for the most accurate system clock. The same thing does IMHO
    apply to the recommendation of using DateTime instead of time.
    
    The only reasonable way to measure timings in the smaller than 100 ms range
    are Python's profiling libraries, e.g. cProfile I did use above. But note,
    that also cProfile only grantees accuracy in the bigger than 100 ms range.
    
    Script & Stuff:
    
    The script below demonstrates, that using time.time() will sometimes return
    faulty timings of zero seconds, while cProfile won't do that. You might have
    to run the script multiple times to get such failure case, because the 
    one-at-a-time accuracy of time.time() depends on many factors.
    
    The most reasonable thing to do here, is to move your profiling "up one 
    level", i.e. do not measure a single call, but rather the loop in your code.
    This will have obviously have the same absolute error, but a much more
    reasonable relative error.
    
    About the "100 ms": From experience this seems to be a very conservative
    figure on modern Windows machines, you can actually expect ~25-50 ms.   
    """
    
    import cProfile
    import pstats
    import time
    
    def profile(func):
        """A simple profiling decorator.
        """
        profiler = cProfile.Profile()
    
        def wrapper(*args, **kwargs):
            result = None
            try:
                result = profiler.runcall(func, *args, **kwargs)
            except Exception as error:
                raise error
            finally:
                stats = pstats.Stats(profiler)
                # To get the full profile do this.
                # stats.strip_dirs().print_stats()
                t = round(stats.total_tt, 3)
                print (f"{func.__name__} took {t} sec.")
            return result
        return wrapper
    
    def timing(func):
        """A time.time() based decorator for timings.
    
        !SHOULD NOT BE USED!
        """
        def wrapper(*args, **kwargs):
            try:
                t = time.time()
                result = func(*args, **kwargs)
                t = round((time.time() - t), 3)
            except Exception as error:
                raise error
            finally:
                print (f"{func.__name__} took {t} sec.")
            return result
        return wrapper
    
    @profile
    def foo_profile():
        """
        """
        [1/3333 for _ in range(100000)]
    
    
    @timing
    def foo_time():
        """
        """
        [1/3333 for _ in range(100000)]
    
    
    def main():
        """
        """
        # Take 10 rounds with each decorator.
        for _ in range(10):
            foo_profile()
        for _ in range(10):
            foo_time()
    
    
    if __name__ == "__main__":
        main()
    


  • What I forgot to mention is, that time.time(), only guarantees a precision of greater or equal to 1 sec. The 100 ms figure I do mention, only applies to the high precision clocks it might or might not be able to poll. Which should always happen on Windows/MacOs, but just to be clear about the precsion of time.time().

    Cheers,
    Ferdinand



  • thank you both @a_block for enduring my beginner questions and zipit always keeping it precise and clean ,,,

    I managed to get an old script to run 20 times faster by just finding junk I was able to cleanup ! Even though as a beginner I sometimes do not know what I am doing this profiling helps to find stupid code!

    so few more scripts to cleanup.