UIMA
  1. UIMA
  2. UIMA-2038

UIMA AS process does not terminate reliably

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 2.3.1AS
    • Fix Version/s: 2.3.1AS
    • Component/s: Async Scaleout
    • Labels:
      None

      Description

      UIMA AS two stop options dont seem to work reliably. Neither 's' nor 'q' on the command line force a clean shutdown of the process. Actually, there is also a related problem. Namely, when the shutdown succeeds it appears that the Shared Connection that all Spring listeners use is not closed which leads to an ugly exception on the broker console. This happens every time the service is terminated. Review listeners shutdown code and make sure that when the last listener terminates the connection is stopped before the process exits. Also, make sure that uima threads from custom pools are daemon threads to allow the jvm to collect them on shutdown. NOTE: AMQ version 4.x internal threads are not daemon threads and there is special code in the listener to wait for them to stop before exiting. Newer AMQ version use daemon threads so shutting down AMQ is much more reliable.

        Activity

        Hide
        Jerry Cwiklik added a comment -

        Minor update to the description

        Show
        Jerry Cwiklik added a comment - Minor update to the description
        Hide
        Jerry Cwiklik added a comment -

        Modified to support orderly shutdown. Major improvements: all uima as threads (in thread pools) are daemon threads, the service closes the connection to the broker before it exits.

        Show
        Jerry Cwiklik added a comment - Modified to support orderly shutdown. Major improvements: all uima as threads (in thread pools) are daemon threads, the service closes the connection to the broker before it exits.
        Hide
        Joern Kottmann added a comment -

        I will try it on my test systems and report back here.

        Show
        Joern Kottmann added a comment - I will try it on my test systems and report back here.
        Hide
        Jerry Cwiklik added a comment -

        Not all listener threads shutdown causing a memory leak while running extended tests.

        Show
        Jerry Cwiklik added a comment - Not all listener threads shutdown causing a memory leak while running extended tests.
        Hide
        Jerry Cwiklik added a comment -

        Modified listener's destroy method to call spring's listeners shutdown() method

        Show
        Jerry Cwiklik added a comment - Modified listener's destroy method to call spring's listeners shutdown() method
        Hide
        Jerry Cwiklik added a comment -

        In extended test setup, stop and start broker between tests to provide better isolation.

        Show
        Jerry Cwiklik added a comment - In extended test setup, stop and start broker between tests to provide better isolation.
        Hide
        Jerry Cwiklik added a comment -

        Modified extended tests to start and stop broker for each test

        Show
        Jerry Cwiklik added a comment - Modified extended tests to start and stop broker for each test
        Hide
        Joern Kottmann added a comment -

        Now I tested it on my test system. I put the new jars of a freshly compiled 2.3.1 trunk onto my test system.

        When pressing "q" I get the following exception:

        2/21/11 3:57:52 PM - 10: org.apache.uima.aae.controller.PrimitiveAnalysisEngineController_impl.stop: INFO: Controller: SearchEngine has stopped
        Exception in thread "main" java.lang.reflect.InvocationTargetException
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:616)
        at org.apache.uima.bootstrap.UimaBootstrap.main(UimaBootstrap.java:98)
        Caused by: java.lang.NoClassDefFoundError: org/springframework/aop/support/AopUtils
        at org.springframework.context.event.GenericApplicationListenerAdapter.supportsEventType(GenericApplicationListenerAdapter.java:57)
        at org.springframework.context.event.AbstractApplicationEventMulticaster.supportsEvent(AbstractApplicationEventMulticaster.java:179)
        at org.springframework.context.event.AbstractApplicationEventMulticaster.getApplicationListeners(AbstractApplicationEventMulticaster.java:140)
        at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:86)
        at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:303)
        at org.springframework.context.support.AbstractApplicationContext.stop(AbstractApplicationContext.java:1242)
        at org.apache.uima.adapter.jms.activemq.SpringContainerDeployer.undeploy(SpringContainerDeployer.java:493)
        at org.apache.uima.adapter.jms.service.UIMA_Service.main(UIMA_Service.java:422)
        ... 5 more
        Caused by: java.lang.ClassNotFoundException: org.springframework.aop.support.AopUtils
        at java.net.URLClassLoader$1.run(URLClassLoader.java:217)
        at java.security.AccessController.doPrivileged(Native Method)
        at java.net.URLClassLoader.findClass(URLClassLoader.java:205)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:321)
        at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:294)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:266)
        ... 13 more

        It looks like I am just missing some spring jar file, didn't you get this error? I checked the distribution produced on the trunk version but could not see an additional or updated jar file, but maybe I missed something.

        Show
        Joern Kottmann added a comment - Now I tested it on my test system. I put the new jars of a freshly compiled 2.3.1 trunk onto my test system. When pressing "q" I get the following exception: 2/21/11 3:57:52 PM - 10: org.apache.uima.aae.controller.PrimitiveAnalysisEngineController_impl.stop: INFO: Controller: SearchEngine has stopped Exception in thread "main" java.lang.reflect.InvocationTargetException at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:616) at org.apache.uima.bootstrap.UimaBootstrap.main(UimaBootstrap.java:98) Caused by: java.lang.NoClassDefFoundError: org/springframework/aop/support/AopUtils at org.springframework.context.event.GenericApplicationListenerAdapter.supportsEventType(GenericApplicationListenerAdapter.java:57) at org.springframework.context.event.AbstractApplicationEventMulticaster.supportsEvent(AbstractApplicationEventMulticaster.java:179) at org.springframework.context.event.AbstractApplicationEventMulticaster.getApplicationListeners(AbstractApplicationEventMulticaster.java:140) at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:86) at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:303) at org.springframework.context.support.AbstractApplicationContext.stop(AbstractApplicationContext.java:1242) at org.apache.uima.adapter.jms.activemq.SpringContainerDeployer.undeploy(SpringContainerDeployer.java:493) at org.apache.uima.adapter.jms.service.UIMA_Service.main(UIMA_Service.java:422) ... 5 more Caused by: java.lang.ClassNotFoundException: org.springframework.aop.support.AopUtils at java.net.URLClassLoader$1.run(URLClassLoader.java:217) at java.security.AccessController.doPrivileged(Native Method) at java.net.URLClassLoader.findClass(URLClassLoader.java:205) at java.lang.ClassLoader.loadClass(ClassLoader.java:321) at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:294) at java.lang.ClassLoader.loadClass(ClassLoader.java:266) ... 13 more It looks like I am just missing some spring jar file, didn't you get this error? I checked the distribution produced on the trunk version but could not see an additional or updated jar file, but maybe I missed something.
        Hide
        Joern Kottmann added a comment -

        OK, now redeployed it to my test system, it seems to shutdown when pressing "q" directly after it started up and did not do any work. When I now start my small uima-as driver and shut it down under load it stays alive.

        I again used jstack to find non-daemon threads:

        "VmThreadGroup65921d50:12e523d4ede:-7ff2_SolrcasAE:Reaper" prio=10 tid=0x00007f7d4c0e7800 nid=0x68f8 in Object.wait() [0x00007f7d4bffe000]
        java.lang.Thread.State: TIMED_WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)

        • waiting on <0x00007f7d80547d10> (a org.apache.uima.aae.spi.transport.vm.VmTransport$1)
          at org.apache.uima.aae.spi.transport.vm.VmTransport$1.run(VmTransport.java:150)
        • locked <0x00007f7d80547d10> (a org.apache.uima.aae.spi.transport.vm.VmTransport$1)

        "threadGroupDestroyer" prio=10 tid=0x00007f7d4c3ac000 nid=0x684d waiting on condition [0x00007f7d503ea000]
        java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)

        • parking to wait for <0x00007f7d625662e0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
          at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
          at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2081)
          at java.util.concurrent.ThreadPoolExecutor.awaitTermination(ThreadPoolExecutor.java:1425)
          at org.apache.uima.adapter.jms.activemq.UimaDefaultMessageListenerContainer.shutdownTaskExecutor(UimaDefaultMessageListenerContainer.java:912)
          at org.apache.uima.adapter.jms.activemq.UimaDefaultMessageListenerContainer$3.run(UimaDefaultMessageListenerContainer.java:942)

        "ActiveMQ Transport: tcp://xxx.net/127.0.0.2:61616" prio=10 tid=0x00007f7d4c160800 nid=0x67dd runnable [0x00007f7d50ff6000]
        java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:146)
        at org.apache.activemq.transport.tcp.TcpBufferedInputStream.fill(TcpBufferedInputStream.java:50)
        at org.apache.activemq.transport.tcp.TcpTransport$2.fill(TcpTransport.java:575)
        at org.apache.activemq.transport.tcp.TcpBufferedInputStream.read(TcpBufferedInputStream.java:58)
        at org.apache.activemq.transport.tcp.TcpTransport$2.read(TcpTransport.java:560)
        at java.io.DataInputStream.readInt(DataInputStream.java:387)
        at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:269)
        at org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:226)
        at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:218)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:201)
        at java.lang.Thread.run(Thread.java:636)

        In the activemq console I can see that one of the two consumers is still connected.

        Show
        Joern Kottmann added a comment - OK, now redeployed it to my test system, it seems to shutdown when pressing "q" directly after it started up and did not do any work. When I now start my small uima-as driver and shut it down under load it stays alive. I again used jstack to find non-daemon threads: "VmThreadGroup65921d50:12e523d4ede:-7ff2_SolrcasAE:Reaper" prio=10 tid=0x00007f7d4c0e7800 nid=0x68f8 in Object.wait() [0x00007f7d4bffe000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) waiting on <0x00007f7d80547d10> (a org.apache.uima.aae.spi.transport.vm.VmTransport$1) at org.apache.uima.aae.spi.transport.vm.VmTransport$1.run(VmTransport.java:150) locked <0x00007f7d80547d10> (a org.apache.uima.aae.spi.transport.vm.VmTransport$1) "threadGroupDestroyer" prio=10 tid=0x00007f7d4c3ac000 nid=0x684d waiting on condition [0x00007f7d503ea000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) parking to wait for <0x00007f7d625662e0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2081) at java.util.concurrent.ThreadPoolExecutor.awaitTermination(ThreadPoolExecutor.java:1425) at org.apache.uima.adapter.jms.activemq.UimaDefaultMessageListenerContainer.shutdownTaskExecutor(UimaDefaultMessageListenerContainer.java:912) at org.apache.uima.adapter.jms.activemq.UimaDefaultMessageListenerContainer$3.run(UimaDefaultMessageListenerContainer.java:942) "ActiveMQ Transport: tcp://xxx.net/127.0.0.2:61616" prio=10 tid=0x00007f7d4c160800 nid=0x67dd runnable [0x00007f7d50ff6000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:146) at org.apache.activemq.transport.tcp.TcpBufferedInputStream.fill(TcpBufferedInputStream.java:50) at org.apache.activemq.transport.tcp.TcpTransport$2.fill(TcpTransport.java:575) at org.apache.activemq.transport.tcp.TcpBufferedInputStream.read(TcpBufferedInputStream.java:58) at org.apache.activemq.transport.tcp.TcpTransport$2.read(TcpTransport.java:560) at java.io.DataInputStream.readInt(DataInputStream.java:387) at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:269) at org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:226) at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:218) at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:201) at java.lang.Thread.run(Thread.java:636) In the activemq console I can see that one of the two consumers is still connected.
        Hide
        Joern Kottmann added a comment -

        Now re-tested with 2.3.1 RC5 and the issue remains. After processing a few CASes the process does not stop when terminated with "q".

        Here are the non-daemon jstack threads:

        "DestroyJavaVM" prio=10 tid=0x00007f24ec2b4000 nid=0x370d waiting on condition [0x0000000000000000]
        java.lang.Thread.State: RUNNABLE

        "VmThreadGroup563b24df:12e70c47767:-7ff2_SolrcasAE:Reaper" prio=10 tid=0x00007f24ec2b5000 nid=0x395f in Object.wait() [0x00007f24ea9cf000]
        java.lang.Thread.State: TIMED_WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)

        • waiting on <0x00007f251e611b00> (a org.apache.uima.aae.spi.transport.vm.VmTransport$1)
          at org.apache.uima.aae.spi.transport.vm.VmTransport$1.run(VmTransport.java:150)
        • locked <0x00007f251e611b00> (a org.apache.uima.aae.spi.transport.vm.VmTransport$1)

        I guess the second thread as a UIMA-AS thread which maybe should be daemon or terminated
        in some way.

        Show
        Joern Kottmann added a comment - Now re-tested with 2.3.1 RC5 and the issue remains. After processing a few CASes the process does not stop when terminated with "q". Here are the non-daemon jstack threads: "DestroyJavaVM" prio=10 tid=0x00007f24ec2b4000 nid=0x370d waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "VmThreadGroup563b24df:12e70c47767:-7ff2_SolrcasAE:Reaper" prio=10 tid=0x00007f24ec2b5000 nid=0x395f in Object.wait() [0x00007f24ea9cf000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) waiting on <0x00007f251e611b00> (a org.apache.uima.aae.spi.transport.vm.VmTransport$1) at org.apache.uima.aae.spi.transport.vm.VmTransport$1.run(VmTransport.java:150) locked <0x00007f251e611b00> (a org.apache.uima.aae.spi.transport.vm.VmTransport$1) I guess the second thread as a UIMA-AS thread which maybe should be daemon or terminated in some way.
        Hide
        Joern Kottmann added a comment -

        Tested as request by Jerry and the issue is now fixed on my test system.

        Show
        Joern Kottmann added a comment - Tested as request by Jerry and the issue is now fixed on my test system.

          People

          • Assignee:
            Jerry Cwiklik
            Reporter:
            Jerry Cwiklik
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development