avalon-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Peter Donald <pe...@apache.org>
Subject Re: phoenix startup bug?
Date Wed, 28 Nov 2001 22:23:03 GMT
Hi,

Looks like you have two instances of phoenix-demo running. At a guess you 
probably did

run --application=../apps/phoenix-demo.sar 

?

This will load phoenix-demo twice - once because it is in the apps directory 
and once because you specified it on the command line. Hmmm ... something 
should be done about that - at the very least a warning of some kind.


On Thu, 29 Nov 2001 04:35, Jar Lyons wrote:
> With debug turned on .... I've been working on getting my application
> going ...
>
> One thing I noticed in the debug log was a msg about the port already
> being in use .... which of
> course was correct.
>
> So I tried to find the other process that had it bound ... obviously
> suspecting an earlier attempt at
> a run to still be lingering around.
>
> But there wasn't one.
>
> So I checked the logs more carefully, and it appears that avalon is
> running through some initialization
> code twice .... including the opening of the port .... in which case the
> 2nd attempt fails ... but the first
> attempt didn't .... so the application appears to be running fine ....
> and you may not be aware at all
> of the failed attempt to launch a dupe block.
>
> So ... considering I'm a rookie at this .... I tried the same thing with
> Paul Hammant's phoenix-demo
> that you can build from his phoenix developers kit.
>
> Same behavior.   Application appears to behave as expected.
>
> Below is the output from phoenix.log:
>
> ---------------------------------------------------------------------------
>-----------
>
> Wed Nov 28 09:33:34 PST 2001 [DEBUG  ] (Phoenix.deployer): Creating a
> BlockInfo for class "phoenixdemo.block.DefaultPDKDemoServer".
> Wed Nov 28 09:33:34 PST 2001 [DEBUG  ] (Phoenix.deployer): Constructed
> BlockInfo object for class phoenixdemo.block.DefaultPDKDemoServer.
> BlockInfo contains 1 services and 0 dependencies.
> Wed Nov 28 09:33:35 PST 2001 [INFO   ] (Phoenix.deployer): Verifying
> that the name specified for Blocks and BlockListeners are valid.
> Wed Nov 28 09:33:35 PST 2001 [INFO   ] (Phoenix.deployer): Verifying
> that the name specified for Blocks and BlockListeners are unique.
> Wed Nov 28 09:33:35 PST 2001 [INFO   ] (Phoenix.deployer): Verifying
> that the specified Dependencies are valid according to BlockInfo.
> Wed Nov 28 09:33:35 PST 2001 [INFO   ] (Phoenix.deployer): Verifying
> that the dependencies of Blocks are valid with respect to other Blocks.
> Wed Nov 28 09:33:35 PST 2001 [INFO   ] (Phoenix.deployer): Verifying
> that there are no circular dependencies between Blocks.
> Wed Nov 28 09:33:35 PST 2001 [INFO   ] (Phoenix.deployer): Verifying
> that the specified Blocks have valid types.
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> getPermissions((file:/usr/local/phoenix/apps/phoenix-demo/blocks/phoenix-de
>mo.bar <no certificates>))
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes):
> getPermissions(file:/usr/local/phoenix/apps/phoenix-demo/blocks/phoenix-dem
>o.bar);
>
> Wed Nov 28 09:33:35 PST 2001 [INFO   ] (Phoenix.deployer): Verifying
> that the specified BlockListeners have valid types.
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.logs): Creating log
> hierarchy for application named "phoenix-demo", using log format version
> "1.0".
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.logs): Creating a log
> category named "" that writes to "default" target at priority "DEBUG".
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.logs): Creating a log
> category named "objectstorage" that writes to "objectstorage-target"
> target at priority "DEBUG".
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> findResource(org/apache/avalon/phoenix/components/application/Resources_en.
>properties)
>
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> Resource
> org/apache/avalon/phoenix/components/application/Resources_en.properties
> not located
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> findResource(org/apache/avalon/phoenix/components/application/Resources_en_
>US.properties)
>
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> Resource
> org/apache/avalon/phoenix/components/application/Resources_en_US.properties
> not located
> Wed Nov 28 09:33:35 PST 2001 [INFO   ] (Phoenix.kernel.phoenix-demo): 1
> Blocks to process for phase "startup". Order of processing =
> [phoenixdemo-server].
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.kernel.phoenix-demo):
> Processing Block named "phoenixdemo-server" through phase "startup".
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ]
> (Phoenix.kernel.phoenix-demo.lifecycle): Block named
> "phoenixdemo-server" is passing through the Creation stage.
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ]
> (Phoenix.kernel.phoenix-demo.lifecycle): Block named
> "phoenixdemo-server" is passing through the Logger initialization stage.
>
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ]
> (Phoenix.kernel.phoenix-demo.lifecycle): Block named
> "phoenixdemo-server" is passing through the Configuration stage.
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ]
> (Phoenix.kernel.phoenix-demo.lifecycle): Block named
> "phoenixdemo-server" is passing through the Initialization stage.
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ]
> (Phoenix.kernel.phoenix-demo.lifecycle): Block named
> "phoenixdemo-server" is passing through the Starting stage.
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.kernel.phoenix-demo):
> Processed Block named "phoenixdemo-server" through phase "startup".
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> findResource(org/apache/avalon/phoenix/components/deployer/Resources_en.pro
>perties)
>
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> Resource
> org/apache/avalon/phoenix/components/deployer/Resources_en.properties
> not located
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> findResource(org/apache/avalon/phoenix/components/deployer/Resources_en_US.
>properties)
>
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> Resource
> org/apache/avalon/phoenix/components/deployer/Resources_en_US.properties
> not located
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.deployer): Adding
> SarEntry named "phoenix-demo" to Kernel with ClassPath =
> [Ljava.lang.String;@60ff2f.
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes): The list of
> classpath entrys for application includes;
> [file:/usr/local/phoenix/apps/phoenix-demo/blocks/phoenix-demo.bar]
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes):
> createPermissionSetFor(file:/-);
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes):
> createPermissionSetFor(file:/usr/local/phoenix/apps/phoenix-demo/blocks/*);
>
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes):
> createPermissionSetFor(file:/usr/local/phoenix/apps/phoenix-demo/lib/*);
>
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes): The list of
> available extensions for application includes; []
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes): The list of
> required extensions for application includes; []
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes): The list of
> "Optional Packages" added to the application includes; []
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.deployer): Creating
> BlockInfo from phoenixdemo/block/DefaultPDKDemoServer.xinfo.
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> findResource(phoenixdemo/block/DefaultPDKDemoServer.xinfo)
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> Resource phoenixdemo/block/DefaultPDKDemoServer.xinfo located
> (jar:file:/usr/local/phoenix/apps/phoenix-demo/blocks/phoenix-demo.bar!/
>
> phoenixdemo/block/DefaultPDKDemoServer.xinfo)
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.deployer): Creating a
> BlockInfo for class "phoenixdemo.block.DefaultPDKDemoServer".
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.deployer): Constructed
> BlockInfo object for class phoenixdemo.block.DefaultPDKDemoServer.
> BlockInfo contains 1 services and 0 dependencies.
> Wed Nov 28 09:33:35 PST 2001 [INFO   ] (Phoenix.deployer): Verifying
> that the name specified for Blocks and BlockListeners are valid.
> Wed Nov 28 09:33:35 PST 2001 [INFO   ] (Phoenix.deployer): Verifying
> that the name specified for Blocks and BlockListeners are unique.
> Wed Nov 28 09:33:35 PST 2001 [INFO   ] (Phoenix.deployer): Verifying
> that the specified Dependencies are valid according to BlockInfo.
> Wed Nov 28 09:33:35 PST 2001 [INFO   ] (Phoenix.deployer): Verifying
> that the dependencies of Blocks are valid with respect to other Blocks.
> Wed Nov 28 09:33:35 PST 2001 [INFO   ] (Phoenix.deployer): Verifying
> that there are no circular dependencies between Blocks.
> Wed Nov 28 09:33:35 PST 2001 [INFO   ] (Phoenix.deployer): Verifying
> that the specified Blocks have valid types.
> Wed Nov 28 09:33:35 PST 2001 [INFO   ] (Phoenix.deployer): Verifying
> that the specified BlockListeners have valid types.
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.logs): Creating log
> hierarchy for application named "phoenix-demo", using log format version
> "1.0".
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.logs): Creating a log
> category named "" that writes to "default" target at priority "DEBUG".
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.logs): Creating a log
> category named "objectstorage" that writes to "objectstorage-target"
> target at priority "DEBUG".
> Wed Nov 28 09:33:35 PST 2001 [INFO   ] (Phoenix.kernel.phoenix-demo): 1
> Blocks to process for phase "startup". Order of processing =
> [phoenixdemo-server].
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.kernel.phoenix-demo):
> Processing Block named "phoenixdemo-server" through phase "startup".
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ]
> (Phoenix.kernel.phoenix-demo.lifecycle): Block named
> "phoenixdemo-server" is passing through the Creation stage.
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ]
> (Phoenix.kernel.phoenix-demo.lifecycle): Block named
> "phoenixdemo-server" is passing through the Logger initialization stage.
>
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ]
> (Phoenix.kernel.phoenix-demo.lifecycle): Block named
> "phoenixdemo-server" is passing through the Configuration stage.
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ]
> (Phoenix.kernel.phoenix-demo.lifecycle): Block named
> "phoenixdemo-server" is passing through the Initialization stage.
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ]
> (Phoenix.kernel.phoenix-demo.lifecycle): Block named
> "phoenixdemo-server" is passing through the Starting stage.
> Wed Nov 28 09:33:35 PST 2001 [ERROR  ]
> (Phoenix.kernel.phoenix-demo.lifecycle): Block named
> "phoenixdemo-server" failed to pass through the Starting stage. (Reason:
> java.lang.RuntimeException: Unable to o
> pen listening port.  It is probably already being listened to.).
> Wed Nov 28 09:33:35 PST 2001 [ERROR  ] (Phoenix.kernel.phoenix-demo):
> There was an error running phase "startup" for Block named
> "phoenixdemo-server". (Reason: Block named "phoenixdemo-server" failed
> to p
> ass through the Starting stage. (Reason: java.lang.RuntimeException:
> Unable to open listening port.  It is probably already being listened
> to.).).
> org.apache.avalon.framework.CascadingException: Block named
> "phoenixdemo-server" failed to pass through the Starting stage. (Reason:
> java.lang.RuntimeException: Unable to open listening port.  It is proba
> bly already being listened to.).
>         at
> org.apache.avalon.phoenix.components.application.LifecycleHelper.fail(Lifec
>ycleHelper.java:417)
>
>         at
> org.apache.avalon.phoenix.components.application.LifecycleHelper.startup(Li
>fecycleHelper.java:220)
>
>         at
> org.apache.avalon.phoenix.components.application.DefaultApplication.runPhas
>e(DefaultApplication.java:177)
>
>         at
> org.apache.avalon.phoenix.components.application.DefaultApplication.start(D
>efaultApplication.java:88)
>
>         at
> org.apache.avalon.phoenix.components.kernel.DefaultKernel.startup(DefaultKe
>rnel.java:124)
>
>         at
> org.apache.avalon.phoenix.components.kernel.DefaultKernel.addApplication(De
>faultKernel.java:171)
>
>         at
> org.apache.avalon.phoenix.components.deployer.DefaultDeployer.deploy(Defaul
>tDeployer.java:166)
>
> rethrown from
> java.lang.RuntimeException: Unable to open listening port.  It is
> probably already being listened to.
>         at phoenixdemo.block.SocketThread.<init>(SocketThread.java:40)
>         at
> phoenixdemo.block.DefaultPDKDemoServer.start(DefaultPDKDemoServer.java:70)
>
>         at
> org.apache.avalon.phoenix.components.application.LifecycleHelper.startup(Li
>fecycleHelper.java:207)
>
>         at
> org.apache.avalon.phoenix.components.application.DefaultApplication.runPhas
>e(DefaultApplication.java:177)
>
>         at
> org.apache.avalon.phoenix.components.application.DefaultApplication.start(D
>efaultApplication.java:88)
>
>         at
> org.apache.avalon.phoenix.components.kernel.DefaultKernel.startup(DefaultKe
>rnel.java:124)
>
>         at
> org.apache.avalon.phoenix.components.kernel.DefaultKernel.addApplication(De
>faultKernel.java:171)
>
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> findResource(org/apache/avalon/phoenix/components/kernel/Resources_en.prope
>rties)
>
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> Resource
> org/apache/avalon/phoenix/components/kernel/Resources_en.properties not
> located
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> findResource(org/apache/avalon/phoenix/components/kernel/Resources_en.prope
>rties)
>
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> Resource
> org/apache/avalon/phoenix/components/kernel/Resources_en.properties not
> located
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> findResource(org/apache/avalon/phoenix/components/kernel/Resources_en_US.pr
>operties)
>
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> Resource
> org/apache/avalon/phoenix/components/kernel/Resources_en_US.properties
> not located
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> findResource(org/apache/avalon/phoenix/components/kernel/Resources_en_US.pr
>operties)
>
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.classes.classloader):
> Resource
> org/apache/avalon/phoenix/components/kernel/Resources_en_US.properties
> not located
> Wed Nov 28 09:33:35 PST 2001 [WARN   ] (Phoenix.kernel): Failed to start
> application phoenix-demo.
> org.apache.avalon.framework.CascadingException: Failed to initialize
> application phoenix-demo.
>         at
> org.apache.avalon.phoenix.components.kernel.DefaultKernel.startup(DefaultKe
>rnel.java:136)
>
>         at
> org.apache.avalon.phoenix.components.kernel.DefaultKernel.addApplication(De
>faultKernel.java:171)
>
>         at
> org.apache.avalon.phoenix.components.deployer.DefaultDeployer.deploy(Defaul
>tDeployer.java:166)
>
>         at
> org.apache.avalon.phoenix.components.embeddor.DefaultEmbeddor.deployFile(De
>faultEmbeddor.java:354)
>
>         at
> org.apache.avalon.phoenix.components.embeddor.DefaultEmbeddor.deployFile(De
>faultEmbeddor.java:348)
>
>         at
> org.apache.avalon.phoenix.components.embeddor.DefaultEmbeddor.deployFiles(D
>efaultEmbeddor.java:336)
>
>         at
> org.apache.avalon.phoenix.components.embeddor.DefaultEmbeddor.deployDefault
>Applications(DefaultEmbeddor.java:326)
>
> rethrown from
> org.apache.avalon.framework.CascadingException: Block named
> "phoenixdemo-server" failed to pass through the Starting stage. (Reason:
> java.lang.RuntimeException: Unable to open listening port.  It is proba
> bly already being listened to.).
>         at
> org.apache.avalon.phoenix.components.application.LifecycleHelper.fail(Lifec
>ycleHelper.java:417)
>
>         at
> org.apache.avalon.phoenix.components.application.LifecycleHelper.startup(Li
>fecycleHelper.java:220)
>
>         at
> org.apache.avalon.phoenix.components.application.DefaultApplication.runPhas
>e(DefaultApplication.java:177)
>
>         at
> org.apache.avalon.phoenix.components.application.DefaultApplication.start(D
>efaultApplication.java:88)
>
>         at
> org.apache.avalon.phoenix.components.kernel.DefaultKernel.startup(DefaultKe
>rnel.java:124)
>
>         at
> org.apache.avalon.phoenix.components.kernel.DefaultKernel.addApplication(De
>faultKernel.java:171)
>
>         at
> org.apache.avalon.phoenix.components.deployer.DefaultDeployer.deploy(Defaul
>tDeployer.java:166)
>
> rethrown from
> java.lang.RuntimeException: Unable to open listening port.  It is
> probably already being listened to.
>         at phoenixdemo.block.SocketThread.<init>(SocketThread.java:40)
>         at
> phoenixdemo.block.DefaultPDKDemoServer.start(DefaultPDKDemoServer.java:70)
>
>         at
> org.apache.avalon.phoenix.components.application.LifecycleHelper.startup(Li
>fecycleHelper.java:207)
>
>         at
> org.apache.avalon.phoenix.components.application.DefaultApplication.runPhas
>e(DefaultApplication.java:177)
>
>         at
> org.apache.avalon.phoenix.components.application.DefaultApplication.start(D
>efaultApplication.java:88)
>
>         at
> org.apache.avalon.phoenix.components.kernel.DefaultKernel.startup(DefaultKe
>rnel.java:124)
>
>         at
> org.apache.avalon.phoenix.components.kernel.DefaultKernel.addApplication(De
>faultKernel.java:171)
>
> Wed Nov 28 09:33:35 PST 2001 [DEBUG  ] (Phoenix.deployer): Adding
> SarEntry named "phoenix-demo" to Kernel with ClassPath =
> [Ljava.lang.String;@60ff2f.

-- 
Cheers,

Pete

"Artists can color the sky red because they know it's blue.  Those of us who
 aren't artists must color things the way they really are or people might 
 think we're stupid." -- Jules Feiffer 

--
To unsubscribe, e-mail:   <mailto:avalon-dev-unsubscribe@jakarta.apache.org>
For additional commands, e-mail: <mailto:avalon-dev-help@jakarta.apache.org>


Mime
View raw message