Statistical Time Consumption

RunTime.py

'''
 # @ Author: Lu Liu
 # @ Create Time: 2024-02-28 18:02:05
 # @ Modified by: Lu Liu
 # @ Modified time: 2024-02-28 18:08:28
 # @ Description:
 '''
import time


class RunTime(object):
    def __init__(self, round_digits=0):
        t_now = self.now()
        self._t_begin = t_now
        self._t_last = t_now
        self._digits = round_digits

    def tik(self):
        self._t_last = self.now()
        return self._t_last

    # def tok(self):
    #     dur = self.duration_ms(self._t_last, self.now(), self._digits)
    #     return dur

    def tok(self):
        t_now = self.now()
        dur = self.duration_ms(self._t_last, t_now, self._digits)
        self._t_last = t_now
        return dur

    def total(self):
        t_now = self.now()
        dur = self.duration_ms(self._t_begin, t_now, self._digits)
        self._t_last = t_now
        return dur

    @staticmethod
    def now():
        return time.time()

    @staticmethod
    def duration_ms(t_begin, t_end, round_digits=0):
        dur = (t_end - t_begin) * 1000
        return round(dur, round_digits)
    
    @staticmethod
    def average_ms(t, n, roud_digits=0):
        dur = t / n
        return round(dur, roud_digits)


def test_RunTime():
    def _mock_process(sec: float):
        time.sleep(sec) # process time

    rt = RunTime(round_digits=0)  # t0: start recording

    _mock_process(1) # It's only counted in the `total`, ~1000ms

    rt.tik() # t1: refresh recording point
    _mock_process(0.3)
    _mock_process(0.2)
    t_proc1 = rt.tok()  # Record the elapsed time from time point `t1`, i.e. ~500ms

    _mock_process(1) # It's only counted in the `total`, ~1000ms

    rt.tik() # t2: refresh recording point
    _mock_process(0.5)
    t_proc2 = rt.tok()  # Record the elapsed time from time point `t2`, i.e. ~500ms

    t_total = rt.total()  # Record the elapsed time from time point `t0`, i.e. ~3000ms

    logging.debug(f'\tTimecost({t_total}ms): proc1 {t_proc1}ms, proc2 {t_proc2}ms.')



if __name__ == '__main__':
    import logging
    logging.basicConfig(level=logging.DEBUG,
                        format="[%(asctime)s] {%(pathname)s:%(lineno)d} %(levelname)s - %(message)s",
                        datefmt='%H:%M:%S')
    
    test_RunTime()

The output on my machine is as follows:

>>> Timecost(3050.0ms): proc1 515.0ms, proc2 513.0ms.

Because time.sleep not that accurate, refer to How accurate is python's time.sleep()?