Code review comment for lp://staging/~jameinel/subunit/omit-times-623654

Thanks for doing this John. I'm sorry it took us so long to get around to your patch. I like the approach of only including 'time:' statements that are relevant to the filtered output, but I think this patch gets it slightly wrong.

For example, given the events::

time: 2010-10-17 20:40:05.577960Z
test: foo
time: 2010-10-17 20:41:05.672960Z
success: foo
time: 2010-10-17 21:29:21.727029Z
test: canonical.testing.layers.ZopelessLayer:tearDown
tags: zope:layer
time: 2010-10-17 21:29:21.727397Z
skip: canonical.testing.layers.ZopelessLayer:tearDown [
tearDown not supported
]

where we are filtering out success and want to see skips. The output should be::

time: 2010-10-17 21:29:21.727029Z
test: canonical.testing.layers.ZopelessLayer:tearDown
time: 2010-10-17 21:29:21.727397Z
skip: canonical.testing.layers.ZopelessLayer:tearDown [ multipart
Content-Type: text/plain
reason
17
tearDown not supported
0
]

Where the output with this patch is::

time: 2010-10-17 20:40:05.577960Z
time: 2010-10-17 21:29:21.727397Z
test: canonical.testing.layers.ZopelessLayer:tearDown
skip: canonical.testing.layers.ZopelessLayer:tearDown [ multipart
Content-Type: text/plain
reason
17
tearDown not supported
0
]

The differences being that the output from this branch includes the first 'time:' statement ever, which is not relevant to the displayed events, and that it excludes the 'time:' statement from between 'test' and 'skip'. There may be a significant chunk of time between a test starting and a test getting its result, and I think we want to show that as long as we're showing time.

As a reminder, a 'time:' statement in a subunit stream means that all subsequent statements can be thought of as occurring at that time, one after the other until the next 'time:' statement.

On a simpler level:
 * there are two tests named test_timing_filtered_w_add_unexpected_success
 * stopTestRun is defined twice