Does Python unittest report errors immediately?

Question

Does Python's unittest module always report errors in strict correspondence to the execution order of the lines in the code tested? Do errors create the possibility of unexpected changes into the code's variables?

I was baffled by a KeyError reported by unittest. The line itself looks okay. On the last line before execution halted, debugging prints of the key requested and the dictionary showed the key was in the dictionary. The key referenced in the KeyError was a different key, but that too seemed to be in the dictionary.

I inserted a counter variable into the outer loop to print the number of outer iterations just before the error line (inside an inner loop), and these do not output in the expected sequence. They come out something like 0, 0, 0, 1, 1, 0, 0, 0, 1, 1, 1, 2, 2, 2 -- when I would expect something like 0, 0, 0, 1, 1, 1, 2, 2, 2. And debugging prints of internal data show unexpected changes from one loop to the next.

Code (with many debugging lines):

def onSave(screen_data):
    counter = 0
    for table, flds_dct in self.target_tables.items():
        print 'TABLE %s' % table
        print 'FIELDS: %s' % flds_dct['fields']
        tbl_screen_data = {}
        for fld in flds_dct['fields']:
            print 'LOOP TOP'
            print 'FIELD: %' % fld
            print 'SCREEN DATA: %s' % screen_data
            print 'COUNTER: %s' % counter
            print 'SCREEN DATA OUTPUT: %s' % screen_data[fld]
            tbl_screen_data[fld] = screen_data[fld]
            print 'LOOP BOTTOM'
        self.tables[table].addEntry(tbl_screen_data)
        counter =+ 1
        print 'OUTER LOOP BOTTOM'

Just before the error, this outputs:

TABLE: questions
FIELDS: ['whatIsYourQuest', 'whatIsYourName', 'whatIsTheAirSpeedOfSwallow']
LOOP TOP
FIELD: whatIsYourQuest
SCREEN DATA: 
{'whatIsYourQuest': 'grail', 
 'whatIsYourName': 'arthur', 
 'whatIsYourFavouriteColour': 'blue', 
 'whatIsTheAirSpeedOfSwallow': 'african or european?', 
 'whatIsCapitalOfAssyria': 'Nineveh'}
    COUNTER: 1
    SCREEN DATA OUTPUT: grail
    LOOP BOTTOM
    OUTER LOOP BOTTOM

But then execution stops and I get this error message:

line 100, in writeData
    print 'SCREEN DATA OUTPUT: %s screen_data[fld]
KeyError: 'whatIsCapitalOfAssyria'

But the error is attributed to a line that has already printed its output, and stops execution after the output of several lines after the line with the error.

As I mentioned above, further debugging shows that the contents of screen_data are changed over the iterations of the loop. Crucially, the dictionary passed in has no key 'whatIsCapitalOfAssyria'.

The absence of that key was the cause of the error. At some point the code asked the screen_data dictionary 'whatIsCapitalOfAssyria', which it couldn't answer, and so of course it was thrown from the Bridge of Death, err, failed. BUT it was kind of hard to see that when the screen_data object output in debugging lines does have the key; and the error condition reported isn't raised until after execution of many more lines, which confuses inspection of the values local to the error.

So how does unittest handle code errors? What am I doing wrong here? How should I be using it to avoid this sort of thing?

EDIT: It might help if I added that the method tested triggers calls on a number of other methods, which triggers calls themselves. I think all of those are reasonably well tested, but perhaps the number of interconnected calls matters.

Answer 1

I think you're seeing the error at the NEXT leg of your for loop, compared to the one with which you see all the output -- try changing the plain print to print>>stderr, statements so that buffering and possible suppression of output is not a risk.