[jira] [Created] (FELIX-6286) Concurrency issue in Gogo runtime Activator

["Pierre De Rop (Jira)" <ji...@apache.org>]

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)