Overriding log methods in XCTestLog subclasses causes Xcode to incorrectly report test results

Originator:neilco
Number:rdar://16689070 Date Originated:22-Apr-2014 07:13 PM
Status:Open Resolved:
Product:Developer Tools Product Version:Xcode 5.1.1
Classification:Crash/Hang/Data Loss Reproducible:Always
 
Summary:
Subclassing XCTestLog to modify the information logged during a test run will result in Xcode displaying false information about the test run. 

Steps to Reproduce:
1. Add a subclass of XCTestLog to your test target
2. Override -testLogWithFormat:arguments: and change the format of the log data before writing to the log file handle.
For example:

#import "RedGreenXCTestLog.h"

NSString *const kXCTTestCaseArgsFormat = @"%@|%s|%.3f";
NSString *const kRGArgsSeparator = @"|";
NSString *const kRGTestCaseFinishFormat = @"Test Case '%@' %s (%.3f seconds).\n";
NSString *const kRGModifiedTestResultFormat = @"%@: %@ (%@s)\n";

@implementation RedGreenXCTestLog

+ (void)load
{
    [[NSUserDefaults standardUserDefaults] setValue:NSStringFromClass(self)
                                             forKey:XCTestObserverClassKey];
}

- (void)testLogWithFormat:(NSString *)format arguments:(va_list)arguments
{
    if (![format isEqualToString:kRGTestCaseFinishFormat]) {
        return;
    }
    
    // Produce output in the form "<RESULT>: <test case> (duration)"
    NSArray *args = NSArrayFromArguments(arguments);
    NSString *formattedLog = [NSString stringWithFormat:kRGModifiedTestResultFormat, [args[1] uppercaseString], args[0], args[2]];
    
    [self.logFileHandle writeData:[formattedLog dataUsingEncoding:NSUTF8StringEncoding]];
}

NSArray *NSArrayFromArguments(va_list arguments)
{
    NSString *s = [[NSString alloc] initWithFormat:kXCTTestCaseArgsFormat arguments:arguments];
    NSArray *args = [s componentsSeparatedByString:kRGArgsSeparator];
    
    return args;
}

@end

3. Write a few tests that will only succeed. 
4. Run the test suite

Expected Results:
Xcode will display a Test Passed HUD, the Test Navigator & the Log Navigator will show that all tests passed. 

Actual Results:
Xcode displays a Test Failed HUD and the Log Navigator displays a warning that the test target did not finish. The Test Navigator correctly shows all tests as having passed.

Comments

My Response to ADR

My goal is to create a custom test reporter that writes to the Debug Console and produces a less verbose output that XCTestLog.

I have found that I can reliably and consistently get Xcode to incorrectly report the test results when the following conditions are met:

  1. A custom XCTestObserver subclass is the only XCTestObserver loaded by the test runner.
  2. The custom XCTestObserver writes to stderr.
  3. The format of the test results that is written to stderr is different to that of XCTestLog.

To demonstrate the issue, I've attached two XCTestObserver subclasses (see the files at https://gist.github.com/neilco/7e64df0431c382b6f5ac):

  • CustomTestLog faithfully reproduces the same output as XCTestLog. When this is the only XCTestObserver loaded by the test runner, Xcode correctly reports the outcome via a HUD and in the Log Navigator.

  • FailingTestLog generates different output to XCTestLog. When this is the only XCTestObserver loaded by the test runner, Xcode will always display a Test Failed HUD and the Log Navigator will always display an error:

"Test target encountered an error (Unexpected TestCaseDidFinish)"

With both subclasses, the Test Navigator reports the correct result every time. My expectation is that the HUD displayed by Xcode and the Log Navigator concur with the Test Navigator.

Apple Developer Relations

Engineering has requested the following:

We'd like to know more about your use case for overriding XCTestLog. Can you describe your goals?

Please provide your response or results by updating your bug report.

Please compress any bundled files (e.g. nested folders) prior to uploading.


Please note: Reports posted here will not necessarily be seen by Apple. All problems should be submitted at bugreport.apple.com before they are posted here. Please only post information for Radars that you have filed yourself, and please do not include Apple confidential information in your posts. Thank you!