You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@ant.apache.org by Stefan Bodewig <bo...@apache.org> on 2010/08/09 09:42:06 UTC
Testlistener Events in JUnit Slows Down Forked Tests in 1.8.x
Hi all,
The short story is that with the changed StreamPumper code and
useAvailable=true forked JUnit tests now take a longer time because the
test time is influenced by the time it takes to send the output for test
events back to Ant.
For more background <http://marc.info/?t=127975171300004&r=1&w=2>.
Testlistener events have been introduced to support advanced UIs that
show progress bars while running the tests
<https://issues.apache.org/bugzilla/show_bug.cgi?id=31885>
If I disable those events, tests in 1.8.x finish as quickly as they do
in 1.7.1.
I plan to add an disableTestListenerEvents (any ideas for a different
name?) attribute to <junit> that can be used to disable Testlistener
events (that's trivial to implement, all the necessary hooks are already
there), set it to false for backwards compatibility reasons and strongly
recommend to set it true unless you really need them (running inside of
NetBeans) in the manual page as well as WHATSNEW.
We could add a YAMP (yet another magic property) ...
Comments?
Stefan
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@ant.apache.org
For additional commands, e-mail: dev-help@ant.apache.org
Re: Testlistener Events in JUnit Slows Down Forked Tests in 1.8.x
Posted by Stefan Bodewig <bo...@apache.org>.
On 2010-08-10, Danny Yates wrote:
> Sorry, I didn't make myself clear. I was actually thinking of using a read
> timeout so that the read call returns periodically and you can test
> interrupted(), but on reflection, you can only do that with sockets.
I think you will be able to do that with NIO2 (at worst emulate it with
async-IO) which is many years away from being usable in Ant's core.
Stefan
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@ant.apache.org
For additional commands, e-mail: dev-help@ant.apache.org
Re: Testlistener Events in JUnit Slows Down Forked Tests in 1.8.x
Posted by Danny Yates <da...@codeaholics.org>.
Sorry, I didn't make myself clear. I was actually thinking of using a read
timeout so that the read call returns periodically and you can test
interrupted(), but on reflection, you can only do that with sockets.
I'll get my coat... ;-)
On 10 August 2010 20:45, Stefan Bodewig <bo...@apache.org> wrote:
> On 2010-08-10, Danny Yates wrote:
>
> > Why does the StreamPumper poll like that?
>
> So it can be interrupted.
>
> > Surely it should just block reading the InputStream?
>
> It used to do just that.
>
> On Windows if a process spawns children (grandchildren of Ant in this
> case) they inherit the streams of their parent. In cases where a
> process forked by Ant spawns new processes and then finishs Ant would
> wait for the grandchildren which is not desired. Instead we want Ant to
> go on once the forked process is done.
>
> > To deal with InterruptedException, you can just do a timed read and
> > test the interrupted flag before looping back to the blocking read.
>
> I'm not sure I follow you here. Are you talking about NIO's Selector
> with "timed read"? When Ant was changed to use polling we still lived
> in Java 1.3 API land and so never looked at NIO options. I'm afraid the
> InputStreams provided by the Process class won't provide
> SelectableChannels, though.
>
> Stefan
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@ant.apache.org
> For additional commands, e-mail: dev-help@ant.apache.org
>
>
Re: Testlistener Events in JUnit Slows Down Forked Tests in 1.8.x
Posted by Stefan Bodewig <bo...@apache.org>.
On 2010-08-10, Danny Yates wrote:
> Why does the StreamPumper poll like that?
So it can be interrupted.
> Surely it should just block reading the InputStream?
It used to do just that.
On Windows if a process spawns children (grandchildren of Ant in this
case) they inherit the streams of their parent. In cases where a
process forked by Ant spawns new processes and then finishs Ant would
wait for the grandchildren which is not desired. Instead we want Ant to
go on once the forked process is done.
> To deal with InterruptedException, you can just do a timed read and
> test the interrupted flag before looping back to the blocking read.
I'm not sure I follow you here. Are you talking about NIO's Selector
with "timed read"? When Ant was changed to use polling we still lived
in Java 1.3 API land and so never looked at NIO options. I'm afraid the
InputStreams provided by the Process class won't provide
SelectableChannels, though.
Stefan
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@ant.apache.org
For additional commands, e-mail: dev-help@ant.apache.org
Re: Testlistener Events in JUnit Slows Down Forked Tests in 1.8.x
Posted by Danny Yates <da...@codeaholics.org>.
Why does the StreamPumper poll like that? Surely it should just block
reading the InputStream?
To deal with InterruptedException, you can just do a timed read and test the
interrupted flag before looping back to the blocking read.
Danny.
On 10 August 2010 20:00, Stefan Bodewig <bo...@apache.org> wrote:
> On 2010-08-10, Jesse Glick wrote:
>
> > On 08/09/2010 03:42 AM, Stefan Bodewig wrote:
> >> I plan to add an disableTestListenerEvents
>
> > First I would like to hear an explanation of why printing a few lines
> > to System.out causes such a big performance hit and why this cannot be
> > fixed.
>
> "such a big" is just the accumulation of many small hits.
>
> A test that takes a few miliseconds without the lines to System.out may
> be unfortunate enough to always print lines just after the StreamPumper
> has entered the sleep call and then must wait until StreamPumper wakes
> up before it can proceed. There is one such line before and after each
> test method and each stands a chance to hit the POLL_TIMEOUT which is
> 100ms.
>
> In the very simple test case Laura provided all test together finish in
> less than 10ms and just one of them hitting the sleep is enough to make
> the entire runtime 10 times as much.
>
> In reality each such line is pretty likely to be written while the
> pumper is sleeping, each line is pretty likely to be delayed by up to
> 100ms, even though it will be a lot shorter than that in most cases. If
> you have many test, the times sum up. This isn't anything you notice in
> a testsuite where individual tests take long - like Ant's own testsuite
> whose runtime is dominated by test methods that take many seconds - but
> in setups with very many very small test.
>
> > Does the problem only occur on Windows?
>
> In 1.8.0, yes. In theory the fix for Bug 48746 has ported the effect to
> any OS with Ant 1.8.1 but I've been unable to see the effect on Linux -
> at least with Laura's small testcase. I must admit I haven't tried it
> again on any OS but Windows after I figured out what was going on.
>
> > And can it be avoided by just removing calls to flush(),
>
> No, that doesn't have any effect. Thinking of it, buffering on the
> testrunner side would help but at the same time make the lines unusable
> for the test listener events that must happen in step with the test to
> be useful.
>
> > possibly using System.err?
>
> Uses a different StreamPumper instance but would suffer from the same
> effect.
>
> >> We could add a YAMP (yet another magic property) ...
>
> > This would be much preferable IMHO. The property would just be set by
> > any container which wants to listen to <junit> progress. (An
> > attribute in the build script is useless for this purpose, even if the
> > default is on - since the user might turn it off for speed of builds
> > in other environments!)
>
> You mean the magic property would enable the events even if the user
> wants to turn them off? Or do you want to turn events off by default
> and enable them based on the magic property? The later would break
> backwards compatibility.
>
> Stefan
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@ant.apache.org
> For additional commands, e-mail: dev-help@ant.apache.org
>
>
Re: Testlistener Events in JUnit Slows Down Forked Tests in 1.8.x
Posted by Jesse Glick <je...@oracle.com>.
On 08/19/2010 08:25 AM, Stefan Bodewig wrote:
> I've added an attribute to enable the events (defaults to false) and a
> magic property that overrides the attribute setting.
OK, though I still think the attribute is useless since the only known use case is for container control.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@ant.apache.org
For additional commands, e-mail: dev-help@ant.apache.org
Re: Testlistener Events in JUnit Slows Down Forked Tests in 1.8.x
Posted by Stefan Bodewig <bo...@apache.org>.
On 2010-08-11, Jesse Glick wrote:
> On 08/10/2010 03:00 PM, Stefan Bodewig wrote:
>> buffering on the testrunner side would help but at the same time make
>> the lines unusable for the test listener events that must happen in
>> step with the test to be useful.
> It would suffice for test listener events to be delivered fairly soon
> after the fact, say within a second or so. Buffering would be fine if
> output were flushed after some delay
It turned out that buffering even without flushing helped but still
made the tests significantly slower in my micro benchmark - and this was
before I even started to implement a flushing thread that certainly had
to ensure output was flushed before the regular events were fired ...
I've added an attribute to enable the events (defaults to false) and a
magic property that overrides the attribute setting.
<http://svn.apache.org/viewvc?view=revision&revision=987139>
Stefan
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@ant.apache.org
For additional commands, e-mail: dev-help@ant.apache.org
Re: Testlistener Events in JUnit Slows Down Forked Tests in 1.8.x
Posted by Jesse Glick <je...@oracle.com>.
On 08/10/2010 03:00 PM, Stefan Bodewig wrote:
> buffering on the
> testrunner side would help but at the same time make the lines unusable
> for the test listener events that must happen in step with the test to
> be useful.
It would suffice for test listener events to be delivered fairly soon after the fact, say within a second or so. Buffering would be fine if output were flushed after some
delay (not just based on exceeding some buffer size). Or you could print to a buffered stream and only flush at one-second intervals, say.
> do you want to turn events off by default and enable them based on the magic property?
Exactly. (Assuming that no proper fix as discussed above is forthcoming.)
> [This] would break backwards compatibility.
Yes, but only from the point of view of Ant containers, of which there are a very limited number (and I do not know if any besides NetBeans use this feature). They need
only begin setting this flag unconditionally, which would be ignored by older versions of Ant. The breakage would only be for people running old versions of containers
with new versions of Ant - an unusual case.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@ant.apache.org
For additional commands, e-mail: dev-help@ant.apache.org
Re: Testlistener Events in JUnit Slows Down Forked Tests in 1.8.x
Posted by Stefan Bodewig <bo...@apache.org>.
On 2010-08-10, Jesse Glick wrote:
> On 08/09/2010 03:42 AM, Stefan Bodewig wrote:
>> I plan to add an disableTestListenerEvents
> First I would like to hear an explanation of why printing a few lines
> to System.out causes such a big performance hit and why this cannot be
> fixed.
"such a big" is just the accumulation of many small hits.
A test that takes a few miliseconds without the lines to System.out may
be unfortunate enough to always print lines just after the StreamPumper
has entered the sleep call and then must wait until StreamPumper wakes
up before it can proceed. There is one such line before and after each
test method and each stands a chance to hit the POLL_TIMEOUT which is
100ms.
In the very simple test case Laura provided all test together finish in
less than 10ms and just one of them hitting the sleep is enough to make
the entire runtime 10 times as much.
In reality each such line is pretty likely to be written while the
pumper is sleeping, each line is pretty likely to be delayed by up to
100ms, even though it will be a lot shorter than that in most cases. If
you have many test, the times sum up. This isn't anything you notice in
a testsuite where individual tests take long - like Ant's own testsuite
whose runtime is dominated by test methods that take many seconds - but
in setups with very many very small test.
> Does the problem only occur on Windows?
In 1.8.0, yes. In theory the fix for Bug 48746 has ported the effect to
any OS with Ant 1.8.1 but I've been unable to see the effect on Linux -
at least with Laura's small testcase. I must admit I haven't tried it
again on any OS but Windows after I figured out what was going on.
> And can it be avoided by just removing calls to flush(),
No, that doesn't have any effect. Thinking of it, buffering on the
testrunner side would help but at the same time make the lines unusable
for the test listener events that must happen in step with the test to
be useful.
> possibly using System.err?
Uses a different StreamPumper instance but would suffer from the same
effect.
>> We could add a YAMP (yet another magic property) ...
> This would be much preferable IMHO. The property would just be set by
> any container which wants to listen to <junit> progress. (An
> attribute in the build script is useless for this purpose, even if the
> default is on - since the user might turn it off for speed of builds
> in other environments!)
You mean the magic property would enable the events even if the user
wants to turn them off? Or do you want to turn events off by default
and enable them based on the magic property? The later would break
backwards compatibility.
Stefan
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@ant.apache.org
For additional commands, e-mail: dev-help@ant.apache.org
Re: Testlistener Events in JUnit Slows Down Forked Tests in 1.8.x
Posted by Jesse Glick <je...@oracle.com>.
On 08/09/2010 03:42 AM, Stefan Bodewig wrote:
> I plan to add an disableTestListenerEvents
First I would like to hear an explanation of why printing a few lines to System.out causes such a big performance hit and why this cannot be fixed. What is waiting for
what to finish? Does the problem only occur on Windows? And can it be avoided by just removing calls to flush(), possibly using System.err?
> We could add a YAMP (yet another magic property) ...
This would be much preferable IMHO. The property would just be set by any container which wants to listen to <junit> progress. (An attribute in the build script is
useless for this purpose, even if the default is on - since the user might turn it off for speed of builds in other environments!)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@ant.apache.org
For additional commands, e-mail: dev-help@ant.apache.org
Re: Testlistener Events in JUnit Slows Down Forked Tests in 1.8.x
Posted by Dominique Devienne <dd...@gmail.com>.
On Mon, Aug 9, 2010 at 2:42 AM, Stefan Bodewig <bo...@apache.org> wrote:
> The short story is that with the changed StreamPumper code and
> useAvailable=true forked JUnit tests now take a longer time because the
> test time is influenced by the time it takes to send the output for test
> events back to Ant.
>
> For more background <http://marc.info/?t=127975171300004&r=1&w=2>.
>
> Testlistener events have been introduced to support advanced UIs that
> show progress bars while running the tests
> <https://issues.apache.org/bugzilla/show_bug.cgi?id=31885>
>
> If I disable those events, tests in 1.8.x finish as quickly as they do
> in 1.7.1.
>
> I plan to add an disableTestListenerEvents (any ideas for a different
> name?) attribute to <junit> that can be used to disable Testlistener
> events (that's trivial to implement, all the necessary hooks are already
> there), set it to false for backwards compatibility reasons and strongly
> recommend to set it true unless you really need them (running inside of
> NetBeans) in the manual page as well as WHATSNEW.
Makes sense.
> We could add a YAMP (yet another magic property) ...
Might be useful as well, yes.
> Comments?
Just a bit thank you? :) --DD
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@ant.apache.org
For additional commands, e-mail: dev-help@ant.apache.org