timing stuff in Python is bad for your knees

A couple months ago I was shacked up recovering from a little operation. In my boredom, I watched Cheers [http://www.hulu.com/cheers] re-runs on Hulu and was dabbling with some Python stuff. I can't even remember exactly what I was doing but I wanted to time some functions. I didn't spend a lot of time looking for existing solutions for some sort of timer I could import, but I didn't like what I did see so I wrote a little one. It's a little more involved than it needs to be, but I was bored out of my mind remember? The logic got a little confusing at times, so I'm sure it's screwed up somewhere. It can record splits, and one can even use the skip() method to skip over timing certain parts of code. For example, if you make a call to a web service, maybe you don't want to time that call since its very reliant on a third party's performance. Maybe you just want to time the other stuff like what you do with the data you get from a third party web service. This is an homage to a stopwatch, hence "stopwitch.py" because a "stopwatch.py" already exists and "witch" is cooler. I'll paste the code below, but first here's an example script that uses it, followed by the output. Basically the code compares appending items to a new list vs. using a list comprehension. from stopwitch import * # Test stopwitch class by creating a new list, "new", from items in an existing list, "old". old = range(1,100000) ap = stopwitch("append") # new stopwitch instance named "append" ... lc = stopwitch("list_comprehension") lcd = stopwitch("list_comprehension_delayed") ### Appending items. ap.start() new = [] for i in old: new.append(i+1) ap.split() ### Using list comprehension. lc.start() new = [i+1 for i in old] lc.split() ### Using list comprehension and use stopwitch.skip() method to skip over superflous sleeps. import time lcd.start() new = [i+1 for i in old] lcd.skip() time.sleep(3) lcd.skip() lcd.skip() time.sleep(.3) lcd.skip() lcd.split() ### Print reports on each way of creating the new list. print ap.json() print lc.json() print lcd.json() And here's the output. The list comprehension seems to always win as it should even though this is a crappy little test. { "append": { "skipped": "0:00:00", "splits": [ { "split": "2015-10-01T10:05:20.048000", "elapsed": "0:00:00.032000" } ], "skips": [], "stop": "2015-10-01T10:05:20.048000", "elapsed": "0:00:00.032000", "start": "2015-10-01T10:05:20.016000" } } { "list_comprehension": { "skipped": "0:00:00", "splits": [ { "split": "2015-10-01T10:05:20.063000", "elapsed": "0:00:00.015000" } ], "skips": [], "stop": "2015-10-01T10:05:20.063000", "elapsed": "0:00:00.015000", "start": "2015-10-01T10:05:20.048000" } } { "list_comprehension_delayed": { "skipped": "0:00:03.323000", "splits": [ { "split": "2015-10-01T10:05:23.402000", "elapsed": "0:00:00.016000" } ], "skips": [ { "start": "2015-10-01T10:05:20.079000", "skipped": "0:00:03.011000", "stop": "2015-10-01T10:05:23.090000" }, { "start": "2015-10-01T10:05:23.090000", "skipped": "0:00:00.312000", "stop": "2015-10-01T10:05:23.402000" } ], "stop": "2015-10-01T10:05:23.402000", "elapsed": "0:00:00.016000", "start": "2015-10-01T10:05:20.063000" } } And here's the stopwitch.py script. #!/usr/bin/python """ stopwitch.py: Class for timing things like a stopwatch. """ __author__ = "Nitin Arora" import datetime import json as js import time class stopwitch(object): def __init__(self, name=None): """ Validates [name]; resets the stopwatch. """ self.name = self.__validate_str(name) self.reset() @classmethod def __validate_str(cls, string, validate=True): """ Validates that [string] is a string. """ if validate == True and string == None: return string elif isinstance(string, basestring) == False: # why "basestring"? see: https://mail.python.org/pipermail/winnipeg/2007-August/000237.html raise TypeError("Argument must be a string.") return else: return string @staticmethod def _to_iso(ss): """ Converts Unix-time/seconds to ISO 8601 format. """ return datetime.datetime.fromtimestamp(ss).isoformat() # per: http://stackoverflow.com/a/24507708 @staticmethod def _to_hms(ss): """ Converts seconds to HH:MM:SS format. """ return str(datetime.timedelta(seconds=ss)) # per: http://stackoverflow.com/a/775095 def __elapsed(self): """ Returns elapsed time between last two saved times. """ if len(self._end) < 2: elapsed = (self._end[-1] - self._begin) - self.__skipped(self._skips) else: elapsed = (self._end[-1] - self._end[-2]) - self.__skipped(self._skips) return elapsed def __skipped(self, skiplist): """ Returns time between active skip times. """ if (len(self._skips)) % 2 != 0: raise Warning("Skips must be paired.") return else: skips = skiplist skips = [(skips[x], skips[x+1]) for x in range(0,len(skips),2)] skipped = sum([float(y-x) for x,y in skips]) return skipped def reset(self): """ Resets the stopwatch. """ self._begin = time.time() self._end = [] self._skips = [] self._skiplog = [] self._splits = [] return def start(self): """ Sets the current time as the starting time. """ self._begin = time.time() return def skip(self): """ Appends the current time to the current list of active skip times. """ self._skips.append(time.time()) return def split(self): """ Sets the current time as the last saved time; records the time of the last two splits; updates log of skipped time; resets list of active skip times. """ if (len(self._skips) % 2) != 0: raise Warning("Skips must be paired; ignoring split.") else: end = time.time() self._end.append(end) self._splits.append((end, self.__elapsed())) self._skiplog += self._skips self._skips = [] return def status(self, formatted=True): """ Returns dictionary containing stopwatch usage data. """ if len(self._skips) > 0 and self._skips[0] > self._splits[-1][0]: raise Warning("Skips must be paired and followed by a split.") return if self._end == []: return {self.name:None} start = self._begin stop = self._end[-1] elapsed = sum([x[1] for x in self._splits]) splits = self._splits skips = [x for x in self._skiplog] skips = [(skips[x], skips[x+1], skips[x+1] - skips[x]) for x in range(0,len(skips),2)] skipped = self.__skipped(self._skiplog) if formatted == True: start = self._to_iso(start) stop = self._to_iso(stop) elapsed = self._to_hms(elapsed) splits = [(self._to_iso(x), self._to_hms(y)) for x,y in splits] skips = [(self._to_iso(x[0]), self._to_iso(x[1]), self._to_hms(x[2])) for x in skips] skipped = self._to_hms(skipped) skips = map(lambda x: {"start": x[0], "stop": x[1], "skipped": x[2]}, skips) splits = map(lambda x: {"split": x[0], "elapsed": x[1]}, splits) report = {self.name: {"start": start, "stop": stop, "elapsed": elapsed, "splits": splits, "skips": skips, "skipped": skipped}} return report def json(self): """ Returns JSON version of status. """ return js.dumps(self.status(), indent=2) # fin.