Merge pull request #73 from inkling/jeff/72_report_suite_level_failur…

…es_in_JUnit

Massive improvements to error reporting and JUnit generation.

Sources/Classes/Logging/SLLogger.h

@@ -246,6 +246,20 @@ void SLLogAsync(NSString *format, ...) NS_FORMAT_FUNCTION(1, 2);
 /// @name Logging Test Progress
 /// -------------------------------------
 
+/**
+ Logs an exception thrown by a test.
+ 
+ The exception will be logged with call-site information if the exception's `userInfo` dictionary 
+ contains both the `SLLoggerExceptionFilenameKey` and `SLLoggerExceptionLineNumberKey` keys.
+
+ See the discussion on the `SLTest (SLTestCase)` category for what constitutes an "expected" exception 
+ (in the context of a test failing due to this exception being raised).
+ 
+ @param exception   The exception to be logged.
+ @param expected    YES if the exception was "expected", otherwise NO.
+ */
+- (void)logException:(NSException *)exception expected:(BOOL)expected;
+
 /**
  Logs that the specified test case has started.
  
@@ -277,3 +291,19 @@ void SLLogAsync(NSString *format, ...) NS_FORMAT_FUNCTION(1, 2);
 - (void)logTest:(NSString *)test caseFail:(NSString *)testCase expected:(BOOL)expected;
 
 @end
+
+
+#pragma mark - Constants
+
+/// Keys for the `userInfo` dictionary of exceptions logged by `-[SLLogger logTestException:expected]`.
+
+/// Object is an `NSString` representing the name of the file in which
+/// the exception occurred.
+extern NSString *const SLLoggerExceptionFilenameKey;
+/// Object is an `NSNumber` whose `integerValue` represents the line number on
+/// which the exception occurred.
+extern NSString *const SLLoggerExceptionLineNumberKey;
+
+/// Prefixes logs of exceptions logged by `-[SLLogger logTestException:expected]`
+/// for which call site information was not provided.
+extern NSString *const SLLoggerUnknownCallSite;

Sources/Classes/Logging/SLLogger.m

@@ -27,6 +27,12 @@
 #import "SLStringUtilities.h"
 
 
+NSString *const SLLoggerExceptionFilenameKey      = @"SLLoggerExceptionFilenameKey";
+NSString *const SLLoggerExceptionLineNumberKey    = @"SLLoggerExceptionLineNumberKey";
+
+NSString *const SLLoggerUnknownCallSite           = @"Unknown location";
+
+
 void SLLog(NSString *format, ...) {
     va_list args;
     va_start(args, format);
@@ -141,7 +147,7 @@ - (void)logTestFinish:(NSString *)test
 }
 
 - (void)logTestAbort:(NSString *)test {
-    [self logError:[NSString stringWithFormat:@"Test \"%@\" terminated abnormally.", test]];
+    [self logMessage:[NSString stringWithFormat:@"Test \"%@\" terminated abnormally.", test]];
 }
 
 - (void)logTestingFinishWithNumTestsExecuted:(NSUInteger)numTestsExecuted
@@ -156,6 +162,28 @@ - (void)logTestingFinishWithNumTestsExecuted:(NSUInteger)numTestsExecuted
 
 @implementation SLLogger (SLTest)
 
+- (void)logException:(NSException *)exception expected:(BOOL)expected {
+    NSString *callSite;
+    NSString *fileName = [exception userInfo][SLLoggerExceptionFilenameKey];
+    NSNumber *lineNumber = [exception userInfo][SLLoggerExceptionLineNumberKey];
+    if (fileName && lineNumber) {
+        callSite = [NSString stringWithFormat:@"%@:%d", fileName, [lineNumber intValue]];
+    } else {
+        callSite = SLLoggerUnknownCallSite;
+    }
+
+    NSString *exceptionDescription;
+    if (expected) {
+        exceptionDescription = [exception reason];
+    } else {
+        exceptionDescription = [NSString stringWithFormat:@"Unexpected exception occurred ***%@*** for reason: %@",
+                                [exception name], [exception reason]];
+    }
+
+    NSString *message = [NSString stringWithFormat:@"%@: %@", callSite, exceptionDescription];
+    [[SLLogger sharedLogger] logError:message];
+}
+
 - (void)logTest:(NSString *)test caseStart:(NSString *)testCase {
     if (dispatch_get_current_queue() != _loggingQueue) {
         dispatch_sync(_loggingQueue, ^{

Sources/Classes/SLTest.h

@@ -161,16 +161,23 @@
  
  See `SLTest (SLTestCase)` for a discussion of test case execution.
  
- @param numCasesExecuted If this is non-`NULL`, on return, this will be set to
- the number of test cases that were executed--which will be the number of test
- cases defined by the receiver's class.
- @param numCasesFailed If this is non-`NULL`, on return, this will be set to the
- number of test cases that failed (the number of test cases that threw exceptions).
- @param numCasesFailedUnexpectedly If this is non-`NULL`, on return, this will
- be set to the number of test cases that failed unexpectedly (those test cases 
- that threw exceptions for other reasons than test assertion failures).
+ @param numCasesExecuted            If this is non-`NULL`, on return, this will be set to
+                                    the number of test cases that were executed--which will be the number of test
+                                    cases defined by the receiver's class.
+ @param numCasesFailed              If this is non-`NULL`, on return, this will be set to the
+                                    number of test cases that failed (the number of test cases that threw exceptions).
+ @param numCasesFailedUnexpectedly  If this is non-`NULL`, on return, this will
+                                    be set to the number of test cases that failed unexpectedly (those test cases
+                                    that threw exceptions for other reasons than test assertion failures).
+ 
+ @return `YES` if the test successfully finished (all test cases were executed, regardless of their individual 
+ success or failure), `NO` otherwise (an exception occurred in test case [set-up](-setUpTest) or [tear-down](-tearDownTest).
+ 
+ @warning If an exception occurs in test case set-up, the test's cases will be skipped.
+ Thus, the caller should use the values returned in `numCasesExecuted`, `numCasesFailed`, 
+ and `numCasesFailedUnexpectedly` if and only if this method returns `YES`.
  */
-- (void)runAndReportNumExecuted:(NSUInteger *)numCasesExecuted
+- (BOOL)runAndReportNumExecuted:(NSUInteger *)numCasesExecuted
                          failed:(NSUInteger *)numCasesFailed
              failedUnexpectedly:(NSUInteger *)numCasesFailedUnexpectedly;
 
@@ -596,23 +603,6 @@
 /// Thrown if a test assertion fails.
 extern NSString *const SLTestAssertionFailedException;
 
-/// Keys for the `userInfo` dictionary of exceptions thrown by, and not caught by,
-/// `SLTest`, i.e. assertion failures in `-setUpTest` and `-tearDownTest` which
-/// should cause the tests to abort.
-
-/// Object is an `NSString` representing the name of the file in which
-/// the exception occurred.
-extern NSString *const SLTestExceptionFilenameKey;
-/// Object is an `NSNumber` whose `integerValue` represents the line number on
-/// which the exception occurred.
-extern NSString *const SLTestExceptionLineNumberKey;
-
-/// Prefixes logs of exceptions, caught by the tests, for which call site information could not be determined:
-/// exceptions thrown in contexts other than failures in assertions or `SLUIAElement` methods.
-/// For `SLUIAElement` exceptions to be tagged with call site information, test writers must wrap
-/// elements in the `UIAElement` macro. See that macro's documentation for an example.
-extern NSString *const SLTestUnknownCallSite;
-
 /// The interval for which `SLAssertTrueWithTimeout` and `SLWaitUntilTrue`
 /// wait before re-evaluating their conditions.
 extern const NSTimeInterval SLWaitUntilTrueRetryDelay;

Sources/Classes/SLTest.m

@@ -31,16 +31,12 @@
 
 
 // All exceptions thrown by SLTest must have names beginning with this prefix
-// so that `-[SLTest logException:inTestCase:]` uses the proper logging format.
+// so that `-[SLTest exceptionByAddingFileInfo:]` can determine whether to attach
+// call site information to exceptions.
 static NSString *const SLTestExceptionNamePrefix       = @"SLTest";
 
 NSString *const SLTestAssertionFailedException  = @"SLTestCaseAssertionFailedException";
 
-NSString *const SLTestExceptionFilenameKey      = @"SLTestExceptionFilenameKey";
-NSString *const SLTestExceptionLineNumberKey    = @"SLTestExceptionLineNumberKey";
-
-NSString *const SLTestUnknownCallSite           = @"Unknown location";
-
 const NSTimeInterval SLWaitUntilTrueRetryDelay = 0.25;
 
 
@@ -234,22 +230,23 @@ + (BOOL)testCaseWithSelectorSupportsCurrentPlatform:(SEL)testCaseSelector {
     return YES;
  }
 
-- (void)runAndReportNumExecuted:(NSUInteger *)numCasesExecuted
+- (BOOL)runAndReportNumExecuted:(NSUInteger *)numCasesExecuted
                          failed:(NSUInteger *)numCasesFailed
              failedUnexpectedly:(NSUInteger *)numCasesFailedUnexpectedly {
     NSUInteger numberOfCasesExecuted = 0, numberOfCasesFailed = 0, numberOfCasesFailedUnexpectedly = 0;
 
-    NSException *setUpOrTearDownException = nil;
+    BOOL testDidFailInSetUpOrTearDown = NO;
     @try {
         [self setUpTest];
     }
     @catch (NSException *exception) {
-        // save exception to throw after tearDownTest
-        setUpOrTearDownException = [self exceptionByAddingFileInfo:exception];
+        [[SLLogger sharedLogger] logException:[self exceptionByAddingFileInfo:exception]
+                                     expected:[[self class] exceptionWasExpected:exception]];
+        testDidFailInSetUpOrTearDown = YES;
     }
 
     // if setUpTest failed, skip the test cases
-    if (!setUpOrTearDownException) {
+    if (!testDidFailInSetUpOrTearDown) {
         NSString *test = NSStringFromClass([self class]);
         for (NSString *testCaseName in [[self class] testCasesToRun]) {
             _currentTestCase = testCaseName;
@@ -273,7 +270,8 @@ - (void)runAndReportNumExecuted:(NSUInteger *)numCasesExecuted
                 @catch (NSException *exception) {
                     caseFailed = YES;
                     failureWasExpected = [[self class] exceptionWasExpected:exception];
-                    [self logException:exception inTestCase:testCaseName asExpected:failureWasExpected];
+                    [[SLLogger sharedLogger] logException:[self exceptionByAddingFileInfo:exception]
+                                                 expected:failureWasExpected];
                 }
 
                 // Only execute the test case if set-up succeeded.
@@ -286,7 +284,8 @@ - (void)runAndReportNumExecuted:(NSUInteger *)numCasesExecuted
                     @catch (NSException *exception) {
                         caseFailed = YES;
                         failureWasExpected = [[self class] exceptionWasExpected:exception];
-                        [self logException:exception inTestCase:testCaseName asExpected:failureWasExpected];
+                        [[SLLogger sharedLogger] logException:[self exceptionByAddingFileInfo:exception]
+                                                     expected:failureWasExpected];
                     }
                 }
 
@@ -296,10 +295,13 @@ - (void)runAndReportNumExecuted:(NSUInteger *)numCasesExecuted
                     [self tearDownTestCaseWithSelector:unfocusedTestCaseSelector];
                 }
                 @catch (NSException *exception) {
+                    BOOL caseHadFailed = caseFailed;
                     caseFailed = YES;
-                    // don't override failureWasExpected if we've already had an unexpected failure
-                    if (!failureWasExpected) failureWasExpected = [[self class] exceptionWasExpected:exception];
-                    [self logException:exception inTestCase:testCaseName asExpected:failureWasExpected];
+                    // don't override `failureWasExpected` if we had already failed
+                    BOOL exceptionWasExpected = [[self class] exceptionWasExpected:exception];
+                    if (!caseHadFailed) failureWasExpected = exceptionWasExpected;
+                    [[SLLogger sharedLogger] logException:[self exceptionByAddingFileInfo:exception]
+                                                 expected:exceptionWasExpected];
                 }
 
                 if (caseFailed) {
@@ -320,20 +322,16 @@ - (void)runAndReportNumExecuted:(NSUInteger *)numCasesExecuted
         [self tearDownTest];
     }
     @catch (NSException *exception) {
-        // ignore the exception if we already failed during setUpTest
-        if (!setUpOrTearDownException) {
-            setUpOrTearDownException = [self exceptionByAddingFileInfo:exception];
-        }
-    }
-
-    // if setUpTest or tearDownTest failed, report their failure rather than returning normally
-    if (setUpOrTearDownException) {
-        @throw setUpOrTearDownException;
+        [[SLLogger sharedLogger] logException:[self exceptionByAddingFileInfo:exception]
+                                     expected:[[self class] exceptionWasExpected:exception]];
+        testDidFailInSetUpOrTearDown = YES;
     }
 
     if (numCasesExecuted) *numCasesExecuted = numberOfCasesExecuted;
     if (numCasesFailed) *numCasesFailed = numberOfCasesFailed;
     if (numCasesFailedUnexpectedly) *numCasesFailedUnexpectedly = numberOfCasesFailedUnexpectedly;
+
+    return !testDidFailInSetUpOrTearDown;
 }
 
 - (void)wait:(NSTimeInterval)interval {
@@ -351,52 +349,29 @@ - (void)clearLastKnownCallSite {
 }
 
 - (NSException *)exceptionByAddingFileInfo:(NSException *)exception {
-    if (_lastKnownFilename) {
-        // If there is file information, insert it into the userInfo dictionary
-        NSMutableDictionary *userInfo = [NSMutableDictionary dictionaryWithDictionary:[exception userInfo]];
-        userInfo[SLTestExceptionFilenameKey] = _lastKnownFilename;
-        userInfo[SLTestExceptionLineNumberKey] = @(_lastKnownLineNumber);
-
-        // call site info is now stale
-        [self clearLastKnownCallSite];
-
-        return [NSException exceptionWithName:[exception name] reason:[exception reason] userInfo:userInfo];
-    } else {
-        return exception;
-    }
-}
-
-+ (BOOL)exceptionWasExpected:(NSException *)exception {
-    return [[exception name] isEqualToString:SLTestAssertionFailedException];
-}
-
-- (void)logException:(NSException *)exception inTestCase:(NSString *)testCase asExpected:(BOOL)expected {
     // Only use the call site information if we have information
     // and if the exception was thrown by `SLTest` or `SLUIAElement`,
     // where the information was likely to have been recorded by an assertion or UIAElement macro.
     // Otherwise it is likely stale.
-    NSString *callSite;
     if (_lastKnownFilename &&
         ([[exception name] hasPrefix:SLTestExceptionNamePrefix] ||
          [[exception name] hasPrefix:SLUIAElementExceptionNamePrefix])) {
-        callSite = [NSString stringWithFormat:@"%@:%d", _lastKnownFilename, _lastKnownLineNumber];
-    } else {
-        callSite = SLTestUnknownCallSite;
+        NSMutableDictionary *userInfo = [NSMutableDictionary dictionaryWithDictionary:[exception userInfo]];
+        userInfo[SLLoggerExceptionFilenameKey] = _lastKnownFilename;
+        userInfo[SLLoggerExceptionLineNumberKey] = @(_lastKnownLineNumber);
+
+        exception = [NSException exceptionWithName:[exception name] reason:[exception reason] userInfo:userInfo];
     }
-    // the call site info is definitely stale at this point
-    [self clearLastKnownCallSite];
 
-    NSString *exceptionDescription;
-    if (expected) {
-        exceptionDescription = [exception reason];
-    } else {
-        exceptionDescription = [NSString stringWithFormat:@"Unexpected exception occurred ***%@*** for reason: %@",
+    // Regardless of whether we used it or not,
+    // call site info is now stale
+    [self clearLastKnownCallSite];
 
-                                                            [exception name], [exception reason]];
-    }
+    return exception;
+}
 
-    NSString *message = [NSString stringWithFormat:@"%@: %@", callSite, exceptionDescription];
-    [[SLLogger sharedLogger] logError:message];
++ (BOOL)exceptionWasExpected:(NSException *)exception {
+    return [[exception name] isEqualToString:SLTestAssertionFailedException];
 }
 
 @end

Sources/Classes/SLTestController.m

@@ -25,6 +25,7 @@
 
 #import "SLLogger.h"
 #import "SLTest.h"
+#import "SLTest+Internal.h"
 #import "SLTerminal.h"
 #import "SLElement.h"
 #import "SLAlert.h"
@@ -257,33 +258,18 @@ - (void)runTests:(NSSet *)tests withCompletionBlock:(void (^)())completionBlock
                 NSString *testName = NSStringFromClass(testClass);
                 [[SLLogger sharedLogger] logTestStart:testName];
 
-                @try {
-                    NSUInteger numCasesExecuted = 0, numCasesFailed = 0, numCasesFailedUnexpectedly = 0;
-
-                    [_currentTest runAndReportNumExecuted:&numCasesExecuted
-                                                   failed:&numCasesFailed
-                                       failedUnexpectedly:&numCasesFailedUnexpectedly];
+                NSUInteger numCasesExecuted = 0, numCasesFailed = 0, numCasesFailedUnexpectedly = 0;
 
+                BOOL testDidFinish = [_currentTest runAndReportNumExecuted:&numCasesExecuted
+                                                                    failed:&numCasesFailed
+                                                        failedUnexpectedly:&numCasesFailedUnexpectedly];
+                if (testDidFinish) {
                     [[SLLogger sharedLogger] logTestFinish:testName
                                       withNumCasesExecuted:numCasesExecuted
                                             numCasesFailed:numCasesFailed
                                 numCasesFailedUnexpectedly:numCasesFailedUnexpectedly];
                     if (numCasesFailed > 0) _numTestsFailed++;
-                }
-                @catch (NSException *e) {
-                    // If an assertion carries call site info, that suggests it was "expected",
-                    // and we log it more tersely than other exceptions.
-                    NSString *fileName = [[e userInfo] objectForKey:SLTestExceptionFilenameKey];
-                    int lineNumber = [[[e userInfo] objectForKey:SLTestExceptionLineNumberKey] intValue];
-                    NSString *message = nil;
-                    if (fileName) {
-                        message = [NSString stringWithFormat:@"%@:%d: %@",
-                                   fileName, lineNumber, [e reason]];
-                    } else {
-                        message = [NSString stringWithFormat:@"Unexpected exception occurred ***%@*** for reason: %@",
-                                   [e name], [e reason]];
-                    }
-                    [[SLLogger sharedLogger] logError:message];
+                } else {
                     [[SLLogger sharedLogger] logTestAbort:testName];
                     _numTestsFailed++;
                 }