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 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.
new = []
for i in old:

### Using list comprehension.
new = [i+1 for i in old]

### Using list comprehension and use stopwitch.skip() method to skip over superflous sleeps.
import time
new = [i+1 for i in old]

### 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.


""" 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)
  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 string
  def _to_iso(ss):
    """ Converts Unix-time/seconds to ISO 8601 format. """
    return datetime.datetime.fromtimestamp(ss).isoformat() # per: http://stackoverflow.com/a/24507708

  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)
      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.")
      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 = []

  def start(self):
    """ Sets the current time as the starting time. """
    self._begin = time.time()
  def skip(self):
    """ Appends the current time to the current list of active skip times. """
  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.")
      end = time.time()
      self._splits.append((end, self.__elapsed()))
      self._skiplog += self._skips
      self._skips = []

  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.")
    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.

    Leave a Comment

    Your email address will not be published. Required fields are marked *