Testing and debugging code in Python

View Github Repository Open presentation in a new window

ghing

See all presentation from ghing

Testing and debugging code in Python

0 0

nicar2016-python-testing-debugging-slides

Slide deck for my NICAR 2016 workshop "Testing and Debugging Code in Python"

On Github ghing / nicar2016-python-testing-debugging-slides

Testing and debugging code in Python

Geoff Hing (geoffhing@gmail.com, @geoffhing)

These slides: http://ghing.github.io/nicar2016-python-testing-debugging-slides

The excercises repo: https://github.com/ghing/nicar2016-python-testing-debugging-exercises/

Getting started

git clone https://github.com/ghing/nicar2016-python-testing-debugging-exercises.git
cd nicar2016-python-testing-debugging-exercises

or go to https://github.com/ghing/nicar2016-python-testing-debugging-exercises/ and

Workshop structure

  • Concept
  • Example
  • Excercise

Solutions

Raise your hand by tweeting me @geoffhing and sharing a link to https://gist.github.com/ or http://pastebin.com/.

You can also check your work

git checkout solutions

Roadmap

  • Running tests
  • Reading error messages
  • Unit testing
  • Outputting debugging messages
  • Debugging with pdb

Running tests

We'll use the CLI for Python's included unittest package.

python -m unittest tests.test_basic

Running a specific test case

python -m unittest tests.test_basic.NoFailuresTestCase

Running a single test

python -m unittest tests.test_basic.NoFailuresTestCase.test_true_is_true

Reading an error message

Let's run a test that causes an unhandled exception in our code.

python -m unittest tests.test_result_loader

Reading an error message

Traceback (most recent call last):
  File "tests/test_result_loader.py", line 13, in test_load_bad_json
    results = loader.load(sample_json)
  File "results/__init__.py", line 5, in load
    parsed = json.loads(s)
  File "/usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/json/__init__.py", line 339, in loads
    return _default_decoder.decode(s)
  File "/usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/json/decoder.py", line 364, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
  File "/usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/json/decoder.py", line 382, in raw_decode
    raise ValueError("No JSON object could be decoded")
ValueError: No JSON object could be decoded

Exercise

Update the result loader so it catches the ValueError and returns an empty list.

Where should we look to fix our code?

Unit Testing

We want to test the smallest possible piece of code.

  • function
  • procedure
  • method

What's the unit?

From tests/test_apstyle.py

class ApStyleNumbersTestCase(unittest.TestCase):
    def test_format_cardinal_number(self):
        self.assertEqual(format_cardinal_number(1), "one")
        self.assertEqual(format_cardinal_number(10), "10")
        self.assertEqual(format_cardinal_number(1050), "1,050")
        self.assertEqual(format_cardinal_number(2000000), "2 million")

unittest

  • fixtures
  • test cases
  • test suites
  • test discovery and running

unittest basics

  • Create a file: test_.py
  • import unittest
  • Subclass unittest.TestCase
  • Implement test methods: def test_something(self): self.fail()

Assertions help us check our expectations

  • assertEqual(a, b)
  • assertNotEqual(a, b)
  • assertTrue(x)
  • assertFalse(x)
  • assertIs(a, b)
  • assertIsNot(a, b)
  • assertIsNone(x)
  • assertIn(a, b)
  • assertNotIn(a, b)
  • assertIsInstance(a, b)
  • assertNotIsInstance(a, b)

Test driven development (TDD)

  • Write tests first
  • Watch it fail
  • Implement unit
  • Re-run tests until they pass

Excercise: write a test case

Implement a test case in tests/test_names.py, then implement parse_name()

Takes input like:

Hing, Geoff, George

Returns

{
    "first_name": "Geoff",
    "last_name": "Hing",
    "middle_name": "George",
    "Suffix": None 
}

Writing testable code

  • We want to be able to run tests quickly and atomically
  • Break functionality into functions, methods, classes and modules
  • How would we test, even if we won't?

Excercise: refactoring for better testing

We're going to refactor results.ChicagoResultsLoader

Which parses data like tests/data/summary.txt

Basic tests:

python -m unittest tests.test_chicago_result_loader

Excercise: refactoring for better testing

Surprise!

Instead of

0079002206900000000000DEM       State's Attorney, Cook County                           Anita Alvarez                         Cook County              001

The data becomes

0079002206900000000000

Excercise: refactoring for better testing

  • Refactor load() to break out the parsing of line into parse_result()
  • Write a test for that new method
  • Write the new method
  • Update load() to use the new method

Fixtures

TestCase.setUp()/TestCase.tearDown()

  • Define the test environment
  • Set up test database
  • Load data from file
  • Create dummy records
  • Create reusable instances

Integration tests

  • Test how units work together
  • Test interfaces to external systems
  • More expensive to run

Next steps

  • Mocks
  • Continuous integration
  • Other runners (nose, unittest2)

Knowing what's going on

pprint

>>> import json
>>> with open('tests/data/ap_elections_loader_recording-1456935370.json') as f:
...     data = json.load(f)
...     print(data['races'][0])

pprint

{u'raceTypeID': u'R', u'statePostal': u'FL', u'raceID': u'10673', u'national': True, u'officeName': u'President', u'lastUpdated': u'2016-03-02T15:42:49Z', u'candidates': [{u'candidateID': u'20408', u'last': u'Bush', u'polNum': u'14561', u'polID': u'1239', u'party': u'GOP', u'ballotOrder': 1, u'first': u'Jeb'}, {u'candidateID': u'20409', u'last': u'Carson', u'polNum': u'14562', u'polID': u'64509', u'party': u'GOP', u'ballotOrder': 2, u'first': u'Ben'}, {u'candidateID': u'20410', u'last': u'Christie', u'polNum': u'14563', u'polID': u'60051', u'party': u'GOP', u'ballotOrder': 3, u'first': u'Chris'}, {u'candidateID': u'20411', u'last': u'Cruz', u'polNum': u'14564', u'polID': u'61815', u'party': u'GOP', u'ballotOrder': 4, u'first': u'Ted'}, {u'candidateID': u'20414', u'last': u'Fiorina', u'polNum': u'14566', u'polID': u'60339', u'party': u'GOP', u'ballotOrder': 5, u'first': u'Carly'}, {u'candidateID': u'20416', u'last': u'Graham', u'polNum': u'14568', u'polID': u'1408', u'party': u'GOP', u'ballotOrder': 7, u'first': u'Lindsey'}, {u'abbrv': u'Huckabe', u'candidateID': u'20419', u'last': u'Huckabee', u'polNum': u'14569', u'polID': u'1187', u'party': u'GOP', u'ballotOrder': 8, u'first': u'Mike'}, {u'candidateID': u'20421', u'last': u'Kasich', u'polNum': u'14571', u'polID': u'36679', u'party': u'GOP', u'ballotOrder': 9, u'first': u'John'}, {u'candidateID': u'20423', u'last': u'Paul', u'polNum': u'14573', u'polID': u'60208', u'party': u'GOP', u'ballotOrder': 10, u'first': u'Rand'}, {u'candidateID': u'20425', u'last': u'Rubio', u'polNum': u'12082', u'polID': u'53044', u'party': u'GOP', u'ballotOrder': 11, u'first': u'Marco'}, {u'candidateID': u'20427', u'last': u'Santorum', u'polNum': u'13890', u'polID': u'1752', u'party': u'GOP', u'ballotOrder': 12, u'first': u'Rick'}, {u'candidateID': u'20428', u'last': u'Trump', u'polNum': u'14574', u'polID': u'8639', u'party': u'GOP', u'ballotOrder': 13, u'first': u'Donald'}, {u'candidateID': u'20429', u'last': u'Gilmore', u'polNum': u'14567', u'polID': u'45650', u'party': u'GOP', u'ballotOrder': 6, u'first': u'Jim'}], u'officeID': u'P', u'party': u'GOP'}

pprint

>>> with open('tests/data/ap_elections_loader_recording-1456935370.json') as f:
...     data = json.load(f)
...     pprint.pprint(data['races'][0])

pprint

{u'candidates': [{u'ballotOrder': 1,
                  u'candidateID': u'20408',
                  u'first': u'Jeb',
                  u'last': u'Bush',
                  u'party': u'GOP',
                  u'polID': u'1239',
                  u'polNum': u'14561'},
                 {u'ballotOrder': 2,
                  u'candidateID': u'20409',
                  u'first': u'Ben',
                  u'last': u'Carson',
                  u'party': u'GOP',
                  u'polID': u'64509',
                  u'polNum': u'14562'},
                 {u'ballotOrder': 3,
                  u'candidateID': u'20410',
                  u'first': u'Chris',
                  u'last': u'Christie',
                  u'party': u'GOP',
                  u'polID': u'60051',
                  u'polNum': u'14563'},
                 {u'ballotOrder': 4,
                  u'candidateID': u'20411',
                  u'first': u'Ted',
                  u'last': u'Cruz',
                  u'party': u'GOP',
                  u'polID': u'61815',
                  u'polNum': u'14564'},
                 {u'ballotOrder': 5,
                  u'candidateID': u'20414',
                  u'first': u'Carly',
                  u'last': u'Fiorina',
                  u'party': u'GOP',
                  u'polID': u'60339',
                  u'polNum': u'14566'},
                 {u'ballotOrder': 7,
                  u'candidateID': u'20416',
                  u'first': u'Lindsey',
                  u'last': u'Graham',
                  u'party': u'GOP',
                  u'polID': u'1408',
                  u'polNum': u'14568'},
                 {u'abbrv': u'Huckabe',
                  u'ballotOrder': 8,
                  u'candidateID': u'20419',
                  u'first': u'Mike',
                  u'last': u'Huckabee',
                  u'party': u'GOP',
                  u'polID': u'1187',
                  u'polNum': u'14569'},
                 {u'ballotOrder': 9,
                  u'candidateID': u'20421',
                  u'first': u'John',
                  u'last': u'Kasich',
                  u'party': u'GOP',
                  u'polID': u'36679',
                  u'polNum': u'14571'},

Logging

  • Loggers
  • Formatters
  • Handlers

Logging basics

import logging
logging.basicConfig(level=logging.DEBUG)
logging.debug("Logging to the root logger")

Our own loggers

import logging
logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
handler = logging.FileHandler('debug_log.txt')
logger.addHandler(handler)
logger.debug("Testing logging debug messages")

Excercise: logging to a file

Update results.ChicagoResultsLoader.load() to use a logger to log the contest code, candidate number, votes and, if available, the contest name, candidate name and party to a file named results_log.txt.

Check yourself with assert 

>>> from types import *
>>> s = "foo"
>>> assert type(s) is StringType, "Oops, s is not a string"
>>> s = 27
>>> assert type(s) is StringType, "Oops, s is not a string"
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
AssertionError: Oops, s is not a string

Check yourself with assert 

def switchemup(items):
    return [items[1].upper(), items[0].upper()]

What assumotions are we making? How could we use assert to check them?

Interactive debugging

  • convenience
  • control

At a specific line in your code

Use pdb.set_trace()

>>> import pdb
>>> def debug_this(i1, i2):
...     result = i1
...     for i in range(5):
...         pdb.set_trace()
...         result += i2
...     return result
...
>>> debug_this()
>>> debug_this(1, 1)
> <stdin>(5)debug_this()
(Pdb)

On last exception

Use pdb.post_mortem() with sys.exc_info() (or pdb.pm())

>>> import pdb
>>> import sys
>>> def debug_this(i1, i2):
...     try:
...         result = i1
...         return i1[i2]
...     except Exception:
...        exc_type, exc_value, exc_traceback = sys.exc_info()
...        pdb.post_mortem(exc_traceback)
...
>>> debug_this(1, 1)
> <stdin>(4)debug_this()

Call a function and enter the debugger

Use pdb.runcall()

>>> import pdb
>>> def debug_this(i1, i2):
...     result = i1
...     for i in range(5):
...         result += i2
...     return result
...
>>> pdb.runcall(debug_this, 1, 1)
> <stdin>(2)debug_this()
(Pdb)

Debugger commands

Most commands have a single character alias.

help <topic>

(q)uit exits the debugging session

(l)ist

python -m unittest tests.test_using_debugger
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(18)test_silly_thing()
-> sillier_things = silly_things(things)
(Pdb) l
 13                     "duck",
 14                     27,
 15                     "",
 16             ]
 17             pdb.set_trace()
 18  ->         sillier_things = silly_things(things)
 19             self.assertEqual(sillier_things[2], "silly duck")

(w)here

python -m unittest tests.test_using_debugger
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(18)test_silly_thing()
-> sillier_things = silly_things(things)
(Pdb) w
  /usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/runpy.py(162)_run_module_as_main()
-> "__main__", fname, loader, pkg_name)
  /usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/runpy.py(72)_run_code()
-> exec code in run_globals
  /usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/unittest/__main__.py(12)<module>()
-> main(module=None)
  /usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/unittest/main.py(95)__init__()
-> self.runTests()
  /usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/unittest/main.py(232)runTests()
-> self.result = testRunner.run(self.test)
  /usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/unittest/runner.py(151)run()
-> test(result)
  /usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/unittest/suite.py(70)__call__()
-> return self.run(*args, **kwds)
  /usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/unittest/suite.py(108)run()
-> test(result)
  /usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/unittest/suite.py(70)__call__()
-> return self.run(*args, **kwds)
  /usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/unittest/suite.py(108)run()
-> test(result)
  /usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/unittest/suite.py(70)__call__()
-> return self.run(*args, **kwds)
  /usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/unittest/suite.py(108)run()
-> test(result)
  /usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/unittest/case.py(393)__call__()
-> return self.run(*args, **kwds)
  /usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/unittest/case.py(329)run()
-> testMethod()
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(18)test_silly_thing()
-> sillier_things = silly_things(things)
                    </module>

(s)tep

python -m unittest tests.test_using_debugger
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(23)test_silly_thing()
-> sillier_things = silly_things(things)
(Pdb) l
 18                     "duck",
 19                     27,
 20                     "",
 21             ]
 22             pdb.set_trace()
 23  ->         sillier_things = silly_things(things)
 24             self.assertEqual(sillier_things[2], "silly duck")
[EOF]
(Pdb) s
--Call--
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(4)silly_things()
-> def silly_things(things):
(Pdb) l
  1     import pdb
  2     import unittest
  3
  4  -> def silly_things(things):
  5         sillier_things = []
  6
  7         for thing in things:
  8             sillier_things.append("silly " + thing)
  9
 10         return sillier_things

(b)reak

python -m unittest tests.test_using_debugger
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(23)test_silly_thing()
-> sillier_things = silly_things(things)
(Pdb) l
 18                     "duck",
 19                     27,
 20                     "",
 21             ]
 22             pdb.set_trace()
 23  ->         sillier_things = silly_things(things)
 24             self.assertEqual(sillier_things[2], "silly duck")
[EOF]
(Pdb) s
--Call--
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(4)silly_things()
-> def silly_things(things):
(Pdb) l
  1     import pdb
  2     import unittest
  3
  4  -> def silly_things(things):
  5         sillier_things = []
  6
  7         for thing in things:
  8             sillier_things.append("silly " + thing)
  9
 10         return sillier_things
 11
(Pdb) b 8
Breakpoint 1 at /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py:8

(c)ontinue

python -m unittest tests.test_using_debugger
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(23)test_silly_thing()
-> sillier_things = silly_things(things)
(Pdb) l
 18                     "duck",
 19                     27,
 20                     "",
 21             ]
 22             pdb.set_trace()
 23  ->         sillier_things = silly_things(things)
 24             self.assertEqual(sillier_things[2], "silly duck")
[EOF]
(Pdb) s
--Call--
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(4)silly_things()
-> def silly_things(things):
(Pdb) l
  1     import pdb
  2     import unittest
  3
  4  -> def silly_things(things):
  5         sillier_things = []
  6
  7         for thing in things:
  8             sillier_things.append("silly " + thing)
  9
 10         return sillier_things
 11
(Pdb) b 8
Breakpoint 1 at /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py:8
(Pdb) c
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(8)silly_things()
-> sillier_things.append("silly " + thing)
(Pdb) c
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(8)silly_things()
-> sillier_things.append("silly " + thing)

Inspecting values

python -m unittest tests.test_using_debugger
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(23)test_silly_thing()
-> sillier_things = silly_things(things)
(Pdb) l
 18                     "duck",
 19                     27,
 20                     "",
 21             ]
 22             pdb.set_trace()
 23  ->         sillier_things = silly_things(things)
 24             self.assertEqual(sillier_things[2], "silly duck")
[EOF]
(Pdb) s
--Call--
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(4)silly_things()
-> def silly_things(things):
(Pdb) l
  1     import pdb
  2     import unittest
  3
  4  -> def silly_things(things):
  5         sillier_things = []
  6
  7         for thing in things:
  8             sillier_things.append("silly " + thing)
  9
 10         return sillier_things
 11
(Pdb) b 8
Breakpoint 1 at /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py:8
(Pdb) c
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(8)silly_things()
-> sillier_things.append("silly " + thing)
(Pdb) c
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(8)silly_things()
-> sillier_things.append("silly " + thing)
(Pdb) print(thing)
kitten

(u)p/(d)own

python -m unittest tests.test_using_debugger
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(23)test_silly_thing()
-> sillier_things = silly_things(things)
(Pdb) s
--Call--
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(4)silly_things()
-> def silly_things(things):
(Pdb) l
  1     import pdb
  2     import unittest
  3
  4  -> def silly_things(things):
  5         sillier_things = []
  6
  7         for thing in things:
  8             sillier_things.append("silly " + thing)
  9
 10         return sillier_things
 11
(Pdb) u
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(23)test_silly_thing()
-> sillier_things = silly_things(things)
(Pdb) import pprint
(Pdb) pprint.pprint(things)
['rabbit', 'kitten', 'duck', 27, '']
(Pdb) d
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(4)silly_things()
-> def silly_things(things):
(Pdb) l
  1     import pdb
  2     import unittest
  3
  4  -> def silly_things(things):
  5         sillier_things = []
  6
  7         for thing in things:
  8             sillier_things.append("silly " + thing)
  9
 10         return sillier_things
 11
(Pdb) s
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(5)silly_things()
-> sillier_things = []
(Pdb) s
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(7)silly_things()
-> for thing in things:
(Pdb) s
> /Users/ghing/Dropbox/nicar2016/nicar2016-python-testing-debugging-excercises/tests/test_using_debugger.py(8)silly_things()
-> sillier_things.append("silly " + thing)
(Pdb) print(thing)
rabbit

Excercise: use the debugger to find wonky data

Run

python -m unittest tests.test_chicago_result_loader.TestBrokenChicagoResultLoader

What exception is raised?

Update results.broken.BrokenChicagoResultsLoader (in results/broken.py) to start the debugger

What line in the data is causing problems? Why?

Thanks!

Geoff Hing (geoffhing@gmail.com, @geoffhing)

These slides: http://ghing.github.io/nicar2016-python-testing-debugging-slides

The excercises repo: https://github.com/ghing/nicar2016-python-testing-debugging-exercises/

Testing and debugging code in Python Geoff Hing (geoffhing@gmail.com, @geoffhing) These slides: http://ghing.github.io/nicar2016-python-testing-debugging-slides The excercises repo: https://github.com/ghing/nicar2016-python-testing-debugging-exercises/