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

    Leave a Comment

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

    *