Feature/fix test output parsing

[icecrystal23]

These changes improve the parsing of the test output and fixes issue #101

First, every command run through the command runner is now run via "script" which ensures that the stdout is line-buffered. This fixes issues I was having with stdout getting corrupted, sometimes resulting in partial lines.

Then I updated the test output parsing (of both XcodeTestTask and TestBuildOutputAppender) to look for the ** TEST SUCCEEDED ** or ** TEST FAILED ** that is output via xcodebuild at the end of a test run. This is a much more reliable method for determining when each test destination run is complete.

[renep]

I'm wondering why you added the following code:
commandList = ["script", "-q", "/dev/null"] + commandList

If you do not what the stderr appear at the stdout, than you can redirect this directly with the ProcessBuilder.

[icecrystal23]

When you pipe output, as it is doing via ProcessBuilder / Process, stdout gets buffered to some arbitrary size and stderr is unbuffered. This was resulting in something like the following in the resulting output: Test case '-[MyTestClass myTestCase]' pa** TEST SUCEEDED ** and then later a line with the rest of the test case line ssed (0.013 seconds).

By running the command via script, stdout is line-buffered (as it would be via a terminal) instead of fully buffered. This means you get complete lines in the output and the lines coming via stdout and stderr are in the correct order.

Notice how I had to "correct" the example files for the TestBuildOutputAppenderTest; this is because the ** TEST SUCCEEDED ** line is output via stderr. It was showing up in the wrong place previously.

After finding the solution via other less obvious means... I found this succinct reference on StackOverflow: http://stackoverflow.com/questions/18995187/xcodebuild-corrupts-test-result-output-when-output-redirected-to-file

[renep]

I think the problem is the following line in the code:

processBuilder.redirectErrorStream(true)

This tells the Process to merge stderr and stdout, and this is the problem. Solving it with the script command is not the correct way I think. It would be better to set the redirectErrorStream to false and also process the error stream in

processInputStream(InputStream inputStream, OutputAppender outputAppender)

Fix the source, not the cause... ;)

[icecrystal23]

I'm not sure that would solve the problem since stdout would still not be flushed until the buffer is full, which is the real problem. If you could find a way to get stdout to auto flush, that would be the best solution.

Sent from my iPad

On Nov 17, 2014, at 7:18 AM, René Pirringer notifications@github.com wrote:

I think the problem is the following line in the code:

processBuilder.redirectErrorStream(true)
This tells the Process to merge stderr and stdout, and this is the problem. Solving it with the script command is not the correct way I think. It would be better to set the redirectErrorStream to false and also process the error stream in

processInputStream(InputStream inputStream, OutputAppender outputAppender)
Fix the source, not the cause... ;)

—
Reply to this email directly or view it on GitHub.

[renep]

I'm not sure that would solve the problem since stdout would still not be flushed until the buffer is full, which is the real problem.

Why is this the problem? The outputAppender only gets the string if the whole line was read.

I also thought the problem is that stderr and stdout both write the output to the same stream.

[icecrystal23]

It's fine for them to be in the same stream, as long as they are in the correct order (i.e., the order xcodebuild is actually outputting them). The problem was that the standard error output was showing up "too early" because the standard output was buffering.

[renep]

In my opinion the steams should not be synced with a shell command, they should be synced by the by the plugin by using two streams, one for stderr and one for stdout.

[icecrystal23]

That will only work if the stdout stream has been flushed when stderr gets some input. I don't know that we can control that from the java side, can we?

[icecrystal23]

Okay, apparently I was mistaken. The ** TEST SUCCEEDED ** output is not going to stderr (I tried implementing two threads, one parsing stderr and out parsing stdout). I am still getting a corrupt line in stdout this way, so the problem must be somewhere else within the way xcodebuild or Java Process is handling stdout. Running it through script is the only thing I have found that works so far.
Any alternate ideas?

[renep]

Have you set

processBuilder.redirectErrorStream(true)

to

processBuilder.redirectErrorStream(false)

?

[icecrystal23]

Yes, and as I said, it isn't actually going to the error stream. I was getting other stuff in the error stream, but not the TEST SUCCEEDED message.

Sent from my iPhone

On Nov 17, 2014, at 10:52 PM, René Pirringer notifications@github.com wrote:

Have you set

to

processBuilder.redirectErrorStream(false)

?
—
Reply to this email directly or view it on GitHub.

[renep]

Do I'm getting this right?
xcodebuild does some output, and the unit tests itself do some with NSLog.
This two outputs are not synced, therefor it can happen that the ** TEST SUCCEEDED ** or Test Suite 'All tests' passed... are mixed up with the NSLog output.
(If this is the case, then this could be also a candidate for a apple radar)

I know that the script will fixe this, but for me this has a bad smell (http://en.wikipedia.org/wiki/Code_smell)

BTW. I never had this issue and a I have lots of unit tests (over 1k) and I also cannot reproduce it.

[icecrystal23]

Regarding what is going on with the output: I don't really know where the messages are coming from. But it is ** TEST SUCCEEDED and Test case '[MyTestCase myTestCase] passed... lines that are usually getting mixed up. I don't know how xcodebuild's test process is generating these.

I did go ahead and open a radar for Apple yesterday. Hopefully they'll respond soon and we'll at least have a better idea about why this is happening.

As evidenced by the stack overflow article and issue #107, I am not the only one experiencing these issues.

[icecrystal23]

On another test related topic, currently the build is not aborting and failing if the unit tests fail to run. Would it be okay to throw a build exception if the unit tests fail to run at all?

[renep]

I have merged you code, but I do the 'script' command only when running the unit tests.

I'm not happy with the script command, but it is fine for now until I find some time so do a better implementation.

I have created a 0.9.14.b version for testing. It would be nice if I get feedback if it works as expected.

I also have anonymized the test output.txt ;)

[icecrystal23]

Awesome, thanks!

Sent from my iPhone

On Nov 24, 2014, at 12:14 AM, René Pirringer notifications@github.com wrote:

I have merged you code, but I do the 'script' command only when running the unit tests.

I'm not happy with the script command, but it is fine for now until I find some time so do a better implementation.

I have created a 0.9.14.b version for testing. It would be nice if I get feedback if it works as expected.

I also have anonymized the test output.txt ;)

—
Reply to this email directly or view it on GitHub.

[icecrystal23]

I tested version 0.9.14.b and it seems to be working; thanks!