Some Eclipse Foundation services are deprecated, or will be soon. Please ensure you've read this important communication.
Bug 366577 - [console] Errors in sysout when running tests
Summary: [console] Errors in sysout when running tests
Status: CLOSED DUPLICATE of bug 514338
Alias: None
Product: Equinox
Classification: Eclipse Project
Component: Components (show other bugs)
Version: 3.8.0 Juno   Edit
Hardware: PC Mac OS X - Carbon (unsup.)
: P3 normal (vote)
Target Milestone: ---   Edit
Assignee: equinox.components-inbox CLA
QA Contact:
URL:
Whiteboard:
Keywords:
: 399986 (view as bug list)
Depends on:
Blocks:
 
Reported: 2011-12-13 11:35 EST by DJ Houghton CLA
Modified: 2017-03-31 08:34 EDT (History)
6 users (show)

See Also:


Attachments
Test project (1.85 KB, application/x-zip)
2012-02-14 13:32 EST, Markus Keller CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description DJ Houghton CLA 2011-12-13 11:35:04 EST
I'm running some of the p2 tests where we spawn a new process to run Eclipse and then come back and analyze the results on disk. While running these tests I'm seeing the following in the console:

STDERR: gogo: InterruptedException: sleep interrupted
STDERR: java.lang.InterruptedException: sleep interrupted
STDERR: 	at java.lang.Thread.sleep(Native Method)
STDERR: 	at org.apache.felix.gogo.shell.Activator.run(Activator.java:72)
STDERR: 	at java.lang.Thread.run(Thread.java:680)

I seem to get one block of these messages for every time we call this code:

Process process = Runtime.getRuntime().exec(commandArray, null, output);
StreamProcessor.start(process.getErrorStream(), StreamProcessor.STDERR, true);
StreamProcessor.start(process.getInputStream(), StreamProcessor.STDOUT, true);
process.waitFor();
return process.exitValue();
Comment 1 DJ Houghton CLA 2011-12-13 11:42:48 EST
Actually I can reproduce this by running eclipse with the reconciler application from the command-line.

eclipse -application org.eclipse.equinox.p2.reconciler.application

I'm using build eclipse-platform-3.8-I20111115-0800-macosx-cocoa-x86_64.tar.gz for my testing.
Comment 2 Lazar Kirchev CLA 2011-12-14 07:25:18 EST
(In reply to comment #1)
> Actually I can reproduce this by running eclipse with the reconciler
> application from the command-line.
> 
> eclipse -application org.eclipse.equinox.p2.reconciler.application
> 
> I'm using build eclipse-platform-3.8-I20111115-0800-macosx-cocoa-x86_64.tar.gz
> for my testing.

I managed to reproduce this with eclipse SDK 3.8 M4, by running the reconciler application with run/debug configuration. 

It turned out that the activator of the Gogo shell bundle starts a thread. This thread's run() method first sleeps 100 ms. It happens that during this time the reconciler application finishes, the Framework tries to stop, so the Gogo shell's Activator.stop() gets called. The stop() method interrupts the thread, which is still sleeping. 
 
Since the interrupt is called by the stop() method, it is not a problem that the run() does not get actually executed. The exception is printed only informatively.
Comment 3 David Williams CLA 2012-02-10 14:23:44 EST
> 
> Since the interrupt is called by the stop() method, it is not a problem that
> the run() does not get actually executed. The exception is printed only
> informatively.

Well ... it is not very informative! 

While trying to develop a simple Eclipse Application with Juno M5, I started with simple "println" to make sure worked. All fine, console log in ID appeared as expected. 

Next, I added a new package (bundle) to manifest.mf file, and a couple of non functioning variables in my "start method". I then tried to "run" again, just to make sure the new bundle could be found, etc., still got my test printline, then I got the message 

gogo: InterruptedException: null
java.lang.InterruptedException
	at java.lang.Thread.sleep(Native Method)
	at java.lang.Thread.sleep(Thread.java:851)
	at org.apache.felix.gogo.shell.Activator.run(Activator.java:72)
	at java.lang.Thread.run(Thread.java:736)


So ... I spent the next two hours trying to figure out what was wrong, and how to open a quality bug report. Then found this bug, which seems to say "it doesn't mean anything". 

Is it a different problem because it says "null" instead of "sleep interrupted"?
Comment 4 Thomas Watson CLA 2012-02-10 14:27:32 EST
(In reply to comment #3)
> Is it a different problem because it says "null" instead of "sleep
> interrupted"?

I suspect that is a difference in the VM used.  DJ and I use that fancy Mac VM ;-)

Lazar, did you happen to open an issue against felix gogo about this?  If/when you do please reference it here.
Comment 5 Markus Keller CLA 2012-02-14 13:32:46 EST
Created attachment 210998 [details]
Test project

I can always reproduce the InterruptedException when running MyTest as a
JUnit Plug-in Test (with Oracle jdk6_27).

When I add something like "Thread.sleep(5);" to the test, I sometimes get different exceptions, e.g.:

gogo: CommandNotFoundException: Command not found: gosh
org.apache.felix.gogo.runtime.CommandNotFoundException: Command not found: gosh
	at org.apache.felix.gogo.runtime.Closure.executeCmd(Closure.java:466)
	at org.apache.felix.gogo.runtime.Closure.executeStatement(Closure.java:395)
	at org.apache.felix.gogo.runtime.Pipe.run(Pipe.java:108)
	at org.apache.felix.gogo.runtime.Closure.execute(Closure.java:183)
	at org.apache.felix.gogo.runtime.Closure.execute(Closure.java:120)
	at org.apache.felix.gogo.runtime.CommandSessionImpl.execute(CommandSessionImpl.java:89)
	at org.apache.felix.gogo.shell.Activator.run(Activator.java:75)
	at java.lang.Thread.run(Thread.java:662)
Comment 6 Lazar Kirchev CLA 2012-02-19 05:50:17 EST
(In reply to comment #5)
> Created attachment 210998 [details]
> Test project
> 
> I can always reproduce the InterruptedException when running MyTest as a
> JUnit Plug-in Test (with Oracle jdk6_27).
> 
> When I add something like "Thread.sleep(5);" to the test, I sometimes get
> different exceptions, e.g.:
> 
> gogo: CommandNotFoundException: Command not found: gosh
> org.apache.felix.gogo.runtime.CommandNotFoundException: Command not found: gosh
>     at org.apache.felix.gogo.runtime.Closure.executeCmd(Closure.java:466)
>     at org.apache.felix.gogo.runtime.Closure.executeStatement(Closure.java:395)
>     at org.apache.felix.gogo.runtime.Pipe.run(Pipe.java:108)
>     at org.apache.felix.gogo.runtime.Closure.execute(Closure.java:183)
>     at org.apache.felix.gogo.runtime.Closure.execute(Closure.java:120)
>     at
> org.apache.felix.gogo.runtime.CommandSessionImpl.execute(CommandSessionImpl.java:89)
>     at org.apache.felix.gogo.shell.Activator.run(Activator.java:75)
>     at java.lang.Thread.run(Thread.java:662)

The reason for the exceptions is the same as for the interrupted exception - the closing of the framework is done while the gogo shell performs initialization actions. The exceptions are different due to timing issues. Actually, if you use a longer interval in Thread.sleep(), no exceptions occur because the shell gets initialized during this sleep.
Comment 7 Lazar Kirchev CLA 2012-02-19 06:07:19 EST
> Lazar, did you happen to open an issue against felix gogo about this?  If/when
> you do please reference it here.

https://issues.apache.org/jira/browse/FELIX-3354
Comment 8 Lazar Kirchev CLA 2013-04-09 02:30:36 EDT
*** Bug 399986 has been marked as a duplicate of this bug. ***
Comment 9 Alexander Levsha CLA 2017-03-31 04:39:02 EDT
To Equinox maintainers: could you update your Apache Felix Gogo dependency so that a fix for this bug would be included in Equinox? Thanks.

The issue was closed in the upstream more than a year ago:
https://issues.apache.org/jira/browse/FELIX-3354
https://issues.apache.org/jira/browse/FELIX-3331
https://issues.apache.org/jira/browse/FELIX-5077
Comment 10 Thomas Watson CLA 2017-03-31 08:34:55 EDT
(In reply to Alexander Levsha from comment #9)
> To Equinox maintainers: could you update your Apache Felix Gogo dependency
> so that a fix for this bug would be included in Equinox? Thanks.
> 
> The issue was closed in the upstream more than a year ago:
> https://issues.apache.org/jira/browse/FELIX-3354
> https://issues.apache.org/jira/browse/FELIX-3331
> https://issues.apache.org/jira/browse/FELIX-5077

Yes, see bug 514338

*** This bug has been marked as a duplicate of bug 514338 ***