Pierre De Rop created FELIX-6286:
------------------------------------
Summary: Concurrency issue in Gogo runtime Activator
Key: FELIX-6286
URL: https://issues.apache.org/jira/browse/FELIX-6286
Project: Felix
Issue Type: Bug
Components: Gogo Runtime
Affects Versions: gogo.runtime-1.1.2
Reporter: Pierre De Rop
Assignee: Pierre De Rop
*Environment:*
jdk: OpenJDK 64-Bit Server VM (AdoptOpenJDK)(build 25.252-b09, mixed mode)
felix: felix-framework-6.0.3
bundles:
* jansi-1.18.jar
* jline-3.13.0.jar
* org.apache.felix.bundlerepository-2.0.10.jar
* org.apache.felix.gogo.command-1.1.1-SNAPSHOT.jar
* org.apache.felix.gogo.jline-1.1.7-SNAPSHOT.jar (or
org.apache.felix.gogo.shell-1.1.3-SNAPSHOT.jar)
* org.apache.felix.gogo.runtime-1.1.3-SNAPSHOT.jar
*Symptoms:*
Sometimes, the gogo bundles don't start up properly:
- when using org.apache.felix.gogo.shell: we may get the following exception:
{code:java}
java -jar bin/felix.jar
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:596)
at
org.apache.felix.gogo.runtime.Closure.executeStatement(Closure.java:526)
at org.apache.felix.gogo.runtime.Closure.execute(Closure.java:415)
at org.apache.felix.gogo.runtime.Pipe.doCall(Pipe.java:416)
at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:229)
at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:59)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
{code}
- when using org.apache.felix.gogo.jline, we may get the following exception:
{code:java}
java -jar bin/felix.jar
bundle://89aa8bfc-38db-4413-9201-f31ffb0fd779_5.0:1/gosh_profile:23.0CommandNotFoundException:
Command not found: try
org.apache.felix.gogo.runtime.CommandNotFoundException: Command not found: try
at org.apache.felix.gogo.runtime.Closure.executeCmd(Closure.java:596)
at
org.apache.felix.gogo.runtime.Closure.executeStatement(Closure.java:526)
at org.apache.felix.gogo.runtime.Closure.execute(Closure.java:415)
at org.apache.felix.gogo.runtime.Pipe.doCall(Pipe.java:416)
at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:229)
at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:59)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748){code}
*When:*
the issue is hard to reproduce. The system must be heavily loaded while the
felix framework is starting up.
To fairly reproduce manually, you can do this:
First: ensure that the org.apache.felix.gogo.runtime bundle is started *AFTER*
other gogo bundles (after gogo jline or gogo shell bundle).
Second: add a delay in
gogo/runtime/src/main/java/org/apache/felix/gogo/runtime/activator/Activator.java
start method, between the CommandProcessor registration and the OSGiCommands
ServiceTracker activation: this will reproduce the issue all the time:
{code:java}
public void start(final BundleContext context) throws Exception
{
threadio = new ThreadIOImpl();
threadio.start();
threadioRegistration =context.registerService(ThreadIO.class.getName(),
threadio, null);
processorRegistration = newProcessor(threadio, context);
System.out.println("XXXXXXXXXXX: sleep");
Thread.sleep(3000);
System.out.println("XXXXXXXXXXX: wakeup");
commandTracker = trackOSGiCommands(context);
commandTracker.open();
{code}
*Work Around:*
start the org.apache.felix.gogo.runtime bundle BEFORE other bundles:
*Analysis:*
my understand is the following: the gogo runtime is doing the following in its
Activator:
# registers the CommandProcessor service
# and after that, it starts tracking OSGI commands.
The issue happens if there are some delay between 1 and 2 above, typically when
the machine is heavily loaded while the felix framework is starting.
So, the other gogo jline and gogo shell Activators are doing this:
# track the CommandProcessor services
# when the CommandProcessor is registered: the shell or jline gogo commands
then register their shell commands in the registry and a thread is then
started. At this point, it is assumed that the shell or jline commands are
already injected into the gogo runtime CommandProcessor. but it won't be the
case if the delay is happening between the time the CommandProcessor is
registered and the gogo runtime service tracker is opened.
*Proposed fix:*
in the *gogo runtime* bundle Activator, register the CommandProcessor *AFTER*
the OSGI commands ServiceTracker has been opened.
By doing so, when the other jline or shell bundles will register their commands
in the OSGI registry, their commands will be registered synchronously in the
CommandProcessor, because at this point the gogo runtime commands service
tracker is already opened.
I'll submit a PR soon.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
