James Server
  1. James Server
  2. JAMES-767

not print exception when shutting down server

    Details

    • Type: Improvement Improvement
    • Status: Resolved
    • Priority: Minor Minor
    • Resolution: Fixed
    • Affects Version/s: 2.3.0
    • Fix Version/s: 3.0-M1
    • Component/s: None
    • Labels:
      None
    • Environment:
      Mac OS X 10.4.8, intel Mac 2.16 GHz dual core, Java VM build 1.5.0_06-112

      Description

      I have set up a James server to test a mail client. I configure it with the IP address of the machine. I do not use DNS, but instead us e-mail addresses like "adam@[10.0.1.6]". When I shut down the server with ctl-C, I get:

      ^CJVM exiting abnormally. Shutting down Phoenix.
      org.apache.avalon.phoenix.containerkit.lifecycle.LifecycleException: Component named "thread-manager" failed to pass through the Destruction stage. (Reason: java.lang.IllegalThreadStateException).
      at org.apache.avalon.phoenix.containerkit.lifecycle.LifecycleHelper.fail(LifecycleHelper.java:354)
      at org.apache.avalon.phoenix.containerkit.lifecycle.LifecycleHelper.shutdown(LifecycleHelper.java:288)
      at org.apache.avalon.phoenix.components.application.DefaultApplication.shutdown(DefaultApplication.java:566)
      at org.apache.avalon.phoenix.components.application.DefaultApplication.doRunPhase(DefaultApplication.java:482)
      at org.apache.avalon.phoenix.components.application.DefaultApplication.runPhase(DefaultApplication.java:409)
      at org.apache.avalon.phoenix.components.application.DefaultApplication.stop(DefaultApplication.java:233)
      at org.apache.avalon.framework.container.ContainerUtil.stop(ContainerUtil.java:292)
      at org.apache.avalon.framework.container.ContainerUtil.shutdown(ContainerUtil.java:66)
      at org.apache.avalon.phoenix.components.kernel.DefaultKernel.shutdown(DefaultKernel.java:346)
      at org.apache.avalon.phoenix.components.kernel.DefaultKernel.removeApplication(DefaultKernel.java:455)
      at org.apache.avalon.phoenix.components.deployer.DefaultDeployer.undeploy(DefaultDeployer.java:244)
      at org.apache.avalon.phoenix.components.deployer.DefaultDeployer.dispose(DefaultDeployer.java:154)
      at org.apache.avalon.framework.container.ContainerUtil.dispose(ContainerUtil.java:306)
      at org.apache.avalon.framework.container.ContainerUtil.shutdown(ContainerUtil.java:67)
      at org.apache.avalon.phoenix.components.embeddor.DefaultEmbeddor.shutdownComponents(DefaultEmbeddor.java:598)
      at org.apache.avalon.phoenix.components.embeddor.DefaultEmbeddor.dispose(DefaultEmbeddor.java:342)
      at org.apache.avalon.framework.container.ContainerUtil.dispose(ContainerUtil.java:306)
      at org.apache.avalon.framework.container.ContainerUtil.shutdown(ContainerUtil.java:67)
      at org.apache.avalon.phoenix.frontends.CLIMain.shutdown(CLIMain.java:326)
      at org.apache.avalon.phoenix.frontends.CLIMain.forceShutdown(CLIMain.java:295)
      at org.apache.avalon.phoenix.frontends.ShutdownHook.run(CLIMain.java:386)
      Caused by: java.lang.IllegalThreadStateException
      at java.lang.ThreadGroup.destroy(ThreadGroup.java:750)
      at org.apache.avalon.excalibur.thread.impl.DefaultThreadPool.dispose(DefaultThreadPool.java:76)
      at org.apache.avalon.framework.container.ContainerUtil.dispose(ContainerUtil.java:306)
      at org.apache.avalon.cornerstone.blocks.threads.AbstractThreadManager.dispose(AbstractThreadManager.java:69)
      at org.apache.avalon.framework.container.ContainerUtil.dispose(ContainerUtil.java:306)
      at org.apache.avalon.phoenix.containerkit.lifecycle.LifecycleHelper.shutdown(LifecycleHelper.java:274)
      ... 19 more

        Activity

        Hide
        Norman Maurer added a comment -

        Fix in trunk. Spring does the shutting down more graceful and so this not happens

        Show
        Norman Maurer added a comment - Fix in trunk. Spring does the shutting down more graceful and so this not happens
        Hide
        Markus Wiederkehr added a comment -

        Sorry, I don't get it: a ThreadGroup is destroyed when it is not empty. As a consequence the for-loop responsible for shutting down all components gets interrupted by an IllegalStateException. How is this not a bug?

        The component "thread-manager" is the last one to be shut down so there is no damage done. But IMO that's only a lucky coincidence.

        Show
        Markus Wiederkehr added a comment - Sorry, I don't get it: a ThreadGroup is destroyed when it is not empty. As a consequence the for-loop responsible for shutting down all components gets interrupted by an IllegalStateException. How is this not a bug? The component "thread-manager" is the last one to be shut down so there is no damage done. But IMO that's only a lucky coincidence.
        Hide
        Norman Maurer added a comment -

        I think thats not really a bug..

        Show
        Norman Maurer added a comment - I think thats not really a bug..
        Hide
        Stefano Bagnara added a comment -

        Markus, thank you for updating us on your progresses!

        Show
        Stefano Bagnara added a comment - Markus, thank you for updating us on your progresses!
        Hide
        Markus Wiederkehr added a comment -

        Fortunately org.apache.avalon.phoenix.components.application.DefaultApplication seems to build a dependency graph when shutting down the components. And thanks to this the component "thread-manager" seems to be the last component that gets shut down. So at least all components are gone before the for-loop gets interrupted by the exception..

        But for what it's worth I think this issue is related to EXLBR-20.

        Show
        Markus Wiederkehr added a comment - Fortunately org.apache.avalon.phoenix.components.application.DefaultApplication seems to build a dependency graph when shutting down the components. And thanks to this the component "thread-manager" seems to be the last component that gets shut down. So at least all components are gone before the for-loop gets interrupted by the exception.. But for what it's worth I think this issue is related to EXLBR-20 .
        Hide
        Markus Wiederkehr added a comment -

        Okay, here is what I have figured out so far. I have included the source code of excalibur-thread-impl-2.1.jar in my Eclipse project. This jar-file contains the class DefaultThreadPool in question.

        This is the critical code:

        73: public void dispose()
        74:

        { 75: m_pool.dispose(); 76: this.destroy(); 77: }

        DefaultThreadPool extends ThreadGroup so this.destroy() in line 76 actually call ThreadGroup.destroy().

        I put an invocation of ThreadGroup.list() between lines 75 and 76 and this is what I get as output:

        org.apache.avalon.excalibur.thread.impl.DefaultThreadPool[name=default,maxpri=10]
        Threaddefault Worker #0,5,default

        So the ThreadGroup cannot be destroyed because there is still a worker thread lingering around.

        The m_pool in line 75 is actually a SoftResourceLimitingPool from excalibur-pool-impl-2.1.jar. This SoftResourceLimitingPool extends DefaultPool which has the following dispose method:

        public final void dispose()
        {
        try
        {
        m_mutex.acquire();
        try
        {
        while( m_ready.size() > 0 )

        { this.removePoolable( (Poolable)m_ready.remove() ); }

        }
        finally

        { m_mutex.release(); }

        }
        catch( Exception e )
        {
        if( getLogger().isWarnEnabled() )

        { getLogger().warn( "Caught an exception disposing of pool", e ); }

        }

        this.m_disposed = true;
        }

        So it removes all elements from its ready pool. But if you take a look at the base class AbstractPool you see that there is also a list of active elements m_active, which seems to be ignored in the dispose method in DefaultPool.

        So to summarize it looks like active threads in the pool are not terminated and as a result the TreadGroup cannot be destroyed.

        Maybe someone can take it from here?

        Show
        Markus Wiederkehr added a comment - Okay, here is what I have figured out so far. I have included the source code of excalibur-thread-impl-2.1.jar in my Eclipse project. This jar-file contains the class DefaultThreadPool in question. This is the critical code: 73: public void dispose() 74: { 75: m_pool.dispose(); 76: this.destroy(); 77: } DefaultThreadPool extends ThreadGroup so this.destroy() in line 76 actually call ThreadGroup.destroy(). I put an invocation of ThreadGroup.list() between lines 75 and 76 and this is what I get as output: org.apache.avalon.excalibur.thread.impl.DefaultThreadPool [name=default,maxpri=10] Thread default Worker #0,5,default So the ThreadGroup cannot be destroyed because there is still a worker thread lingering around. The m_pool in line 75 is actually a SoftResourceLimitingPool from excalibur-pool-impl-2.1.jar. This SoftResourceLimitingPool extends DefaultPool which has the following dispose method: public final void dispose() { try { m_mutex.acquire(); try { while( m_ready.size() > 0 ) { this.removePoolable( (Poolable)m_ready.remove() ); } } finally { m_mutex.release(); } } catch( Exception e ) { if( getLogger().isWarnEnabled() ) { getLogger().warn( "Caught an exception disposing of pool", e ); } } this.m_disposed = true; } So it removes all elements from its ready pool. But if you take a look at the base class AbstractPool you see that there is also a list of active elements m_active, which seems to be ignored in the dispose method in DefaultPool. So to summarize it looks like active threads in the pool are not terminated and as a result the TreadGroup cannot be destroyed. Maybe someone can take it from here?
        Hide
        Stefano Bagnara added a comment -

        It is an issue in a component we use. In the standard usage for james this should be harmless because the jvm is finally stopped with no issue (or at least we haven't received feedback about issues related to this exception but your).

        We didn't change our code related to that component in james 2.3, but we upgraded most of our dependencies.

        Probably the newer component have an issue but no one investigated on it as this is not a major issue for most people.

        The bug is here and is open, if anyone will investigate the issue and will find/fix the problem he/she can add it to this issue.

        Show
        Stefano Bagnara added a comment - It is an issue in a component we use. In the standard usage for james this should be harmless because the jvm is finally stopped with no issue (or at least we haven't received feedback about issues related to this exception but your). We didn't change our code related to that component in james 2.3, but we upgraded most of our dependencies. Probably the newer component have an issue but no one investigated on it as this is not a major issue for most people. The bug is here and is open, if anyone will investigate the issue and will find/fix the problem he/she can add it to this issue.
        Hide
        Markus Wiederkehr added a comment -

        This also happens with phoenix.sh start/stop. The only difference is that the console output (including the ugly stacktrace) is redirected to temp/phoenix.console.

        Stefano, may I ask why you consider this to be harmless?

        I have a setup where the VM does not exit when James gets stopped. This can be accomplished by setting up the classpath manually and invoking org.apache.avalon.phoenix.frontends.CLIMain.main() and CLIMain.shutdown() to start and stop Phoenix including James. I know this might be a bit brutal but it has always worked without problems with older versions of James (or Phoenix respectively).

        So because in my case the VM continues to run I am a bit worried about this one.

        A brief look into org.apache.avalon.phoenix.components.application.DefaultApplication.doRunPhase(String) seems to indicate that the loop that is supposed to shut down all components gets interrupted once an exception occurs. So subsequent components are not shut down at all.

        Show
        Markus Wiederkehr added a comment - This also happens with phoenix.sh start/stop. The only difference is that the console output (including the ugly stacktrace) is redirected to temp/phoenix.console. Stefano, may I ask why you consider this to be harmless? I have a setup where the VM does not exit when James gets stopped. This can be accomplished by setting up the classpath manually and invoking org.apache.avalon.phoenix.frontends.CLIMain.main() and CLIMain.shutdown() to start and stop Phoenix including James. I know this might be a bit brutal but it has always worked without problems with older versions of James (or Phoenix respectively). So because in my case the VM continues to run I am a bit worried about this one. A brief look into org.apache.avalon.phoenix.components.application.DefaultApplication.doRunPhase(String) seems to indicate that the loop that is supposed to shut down all components gets interrupted once an exception occurs. So subsequent components are not shut down at all.
        Hide
        Stefano Bagnara added a comment -

        IIRC I saw the error the first time after upgrade phoenix to the current version and the whole cornerstone/excalibur libs to the latest available. Almost every jar we depend changed in that moment, so it is difficult to know where is the problem. I never considered this critical, so I never investigated on this.

        Show
        Stefano Bagnara added a comment - IIRC I saw the error the first time after upgrade phoenix to the current version and the whole cornerstone/excalibur libs to the latest available. Almost every jar we depend changed in that moment, so it is difficult to know where is the problem. I never considered this critical, so I never investigated on this.
        Hide
        Bernd Fondermann added a comment -

        As far as I remember, previous versions of James did not show exceptions on ctrl-c.

        As you can see from the stacktrace, ctrl-c is triggering a shutdown hook which is trying to orderly shut down phoenix. Why is the stop script working and the hook isn't?
        Maybe at some point a bug has been introduced within phoenix.

        Show
        Bernd Fondermann added a comment - As far as I remember, previous versions of James did not show exceptions on ctrl-c. As you can see from the stacktrace, ctrl-c is triggering a shutdown hook which is trying to orderly shut down phoenix. Why is the stop script working and the hook isn't? Maybe at some point a bug has been introduced within phoenix.
        Hide
        Norman Maurer added a comment -

        What you asspect when using ctrl-c ? For sure it will throw an exception... You should use phoenix.sh start/stop when using as startup script. This will throw no exception.. Anyway the exception is not importent

        Show
        Norman Maurer added a comment - What you asspect when using ctrl-c ? For sure it will throw an exception... You should use phoenix.sh start/stop when using as startup script. This will throw no exception.. Anyway the exception is not importent

          People

          • Assignee:
            Norman Maurer
            Reporter:
            Ray Kiddy
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development