multiple wadi WARN messages during server start
-----------------------------------------------
Key: GERONIMO-3709
URL: https://issues.apache.org/jira/browse/GERONIMO-3709
Project: Geronimo
Issue Type: Bug
Security Level: public (Regular issues)
Components: Clustering
Affects Versions: 2.1
Reporter: Kevan Miller
Fix For: 2.1
I'm seeing lots of WARNING messages from WADI during server start. The messages
really look like info messages to me. I've also seen warning messages and
exception stack traces during shutdown. We need to get things quieted down...
Here's a sample:
bash-3.2$ ./geronimo.sh run --long
Using GERONIMO_BASE:
/Users/kevan/geronimo/server/trunk/target/geronimo-jetty6-javaee5-2.1-SNAPSHOT
Using GERONIMO_HOME:
/Users/kevan/geronimo/server/trunk/target/geronimo-jetty6-javaee5-2.1-SNAPSHOT
Using GERONIMO_TMPDIR: var/temp
Using JRE_HOME:
/System/Library/Frameworks/JavaVM.framework/Versions/CurrentJDK/Home
09:27:57,977 WARN [AbstractGBeanReference] GBean references are not using
proxies
Booting Geronimo Kernel (in Java 1.5.0_13)...
Module 1/59 org.apache.geronimo.configs/ca-helper-jetty/2.1-SNAPSHOT/car
started in 1.715s
Module 2/59 org.apache.geronimo.configs/jasper/2.1-SNAPSHOT/car
started in .000s
Module 3/59 org.apache.geronimo.configs/j2ee-server/2.1-SNAPSHOT/car
started in .000s
Module 4/59 org.apache.geronimo.configs/rmi-naming/2.1-SNAPSHOT/car
started in .000s
Module 5/59 org.apache.geronimo.configs/j2ee-system/2.1-SNAPSHOT/car
started in .000s
Module 6/59 org.apache.geronimo.configs/jee-specs/2.1-SNAPSHOT/car
started in .000s
Module 7/59
org.apache.geronimo.configs/server-security-config/2.1-SNAPSHOT/car
started in .000s
Module 8/59 org.apache.geronimo.configs/j2ee-security/2.1-SNAPSHOT/car
started in .000s
Module 9/59 org.apache.geronimo.configs/transaction/2.1-SNAPSHOT/car
started in .000s
Module 10/59 org.apache.geronimo.configs/myfaces-deployer/2.1-SNAPSHOT/car
started in .627s
Module 11/59 org.apache.geronimo.configs/myfaces/2.1-SNAPSHOT/car
started in .007s
Module 12/59 org.apache.geronimo.configs/j2ee-deployer/2.1-SNAPSHOT/car
started in .000s
Module 13/59
org.apache.geronimo.configs/geronimo-gbean-deployer/2.1-SNAPSHOT/car
started in .000s
Module 14/59 org.apache.geronimo.configs/xmlbeans/2.1-SNAPSHOT/car
started in .000s
Module 15/59 org.apache.geronimo.configs/activemq-ra/2.1-SNAPSHOT/car
started in 3.145s
Module 16/59 org.apache.geronimo.configs/activemq-broker/2.1-SNAPSHOT/car
started in .001s
Module 17/59 org.apache.geronimo.configs/system-database/2.1-SNAPSHOT/car
started in .000s
Module 18/59 org.apache.geronimo.configs/connector-deployer/2.1-SNAPSHOT/car
started in .090s
Module 19/59 org.apache.geronimo.configs/jasper-deployer/2.1-SNAPSHOT/car
started in .016s
Module 20/59 org.apache.geronimo.configs/jetty6-deployer/2.1-SNAPSHOT/car
started in .101s
Module 21/59 org.apache.geronimo.configs/jetty6/2.1-SNAPSHOT/car
started in .000s
Module 22/59 org.apache.geronimo.configs/clustering/2.1-SNAPSHOT/car
started in .074s
Module 23/59 org.apache.geronimo.configs/webservices-common/2.1-SNAPSHOT/car
started in .000s
Module 24/59 org.apache.geronimo.configs/jaxws-ejb-deployer/2.1-SNAPSHOT/car
started in .090s
Module 25/59 org.apache.geronimo.configs/jaxws-deployer/2.1-SNAPSHOT/car
started in .000s
Module 26/59 org.apache.geronimo.configs/openejb-deployer/2.1-SNAPSHOT/car
started in .000s
Module 27/59 org.apache.geronimo.configs/openejb/2.1-SNAPSHOT/car
started in .575s
Module 28/59 org.apache.geronimo.configs/openjpa/2.1-SNAPSHOT/car
started in .000s
Module 29/59 org.apache.geronimo.configs/axis2/2.1-SNAPSHOT/car
started in .000s
Module 30/59 org.apache.geronimo.configs/axis2-ejb/2.1-SNAPSHOT/car
started in .000s
Module 31/59 org.apache.geronimo.plugins/system-database-jetty/2.1-SNAPSHOT/car
started in 4.422s
Module 32/59 org.apache.geronimo.plugins/console-jetty/2.1-SNAPSHOT/car
started in .000s
Module 33/59 org.apache.geronimo.plugins/pluto-support/2.1-SNAPSHOT/car
started in .000s
Module 34/59 org.apache.geronimo.configs/spring/2.1-SNAPSHOT/car
started in .000s
Module 35/59 org.apache.geronimo.configs/transformer-agent/2.1-SNAPSHOT/car
started in .001s
Module 36/59 org.apache.geronimo.configs/remote-deploy-jetty/2.1-SNAPSHOT/car
started in .082s
Module 37/59 org.apache.geronimo.configs/cxf-ejb/2.1-SNAPSHOT/car
started in .000s
Module 38/59 org.apache.geronimo.configs/cxf/2.1-SNAPSHOT/car
started in .000s
Module 39/59 org.apache.geronimo.plugins/debugviews-jetty/2.1-SNAPSHOT/car
started in .449s
Module 40/59 org.apache.geronimo.configs/dojo-jetty6/2.1-SNAPSHOT/car
started in .000s
Module 41/59
org.apache.geronimo.configs/persistence-jpa10-deployer/2.1-SNAPSHOT/car
started in .073s
Module 42/59 org.apache.geronimo.plugins/activemq-jetty/2.1-SNAPSHOT/car
started in .648s
Module 43/59
org.apache.geronimo.configs/jetty6-clustering-wadi/2.1-SNAPSHOT/car Dec
16, 2007 9:28:14 AM org.apache.catalina.tribes.transport.ReceiverBase bind
INFO: Receiver Server Socket bound to:/10.0.1.200:4000
Dec 16, 2007 9:28:14 AM org.codehaus.wadi.tribes.WadiMemberInterceptor start
INFO: memberStart
local:org.apache.catalina.tribes.membership.MemberImpl[tcp://10.0.1.200:4000,10.0.1.200,4000,
alive=0,id={-31 -103 29 40 72 82 66 -11 -122 116 -49 -123 -114 -110 -11 121 },
payload={-84 -19 0 5 115 114 0 50 111 ...(421)}, command={}, domain={68 69 70
65 85 76 84 95 67 ...(15)}, ] notify:false peer:NODE
Dec 16, 2007 9:28:14 AM org.apache.catalina.tribes.membership.McastServiceImpl
setupSocket
INFO: Setting cluster mcast soTimeout to 500
Dec 16, 2007 9:28:14 AM org.apache.catalina.tribes.membership.McastServiceImpl
waitForMembers
INFO: Sleeping for 1000 milliseconds to establish cluster membership, start
level:4
Dec 16, 2007 9:28:15 AM org.apache.catalina.tribes.membership.McastServiceImpl
waitForMembers
INFO: Done sleeping, membership established, start level:4
Dec 16, 2007 9:28:15 AM org.apache.catalina.tribes.membership.McastServiceImpl
waitForMembers
INFO: Sleeping for 1000 milliseconds to establish cluster membership, start
level:8
Dec 16, 2007 9:28:16 AM org.apache.catalina.tribes.membership.McastServiceImpl
waitForMembers
INFO: Done sleeping, membership established, start level:8
Dec 16, 2007 9:28:16 AM org.codehaus.wadi.tribes.WadiMemberInterceptor start
INFO: memberStart
local:org.apache.catalina.tribes.membership.MemberImpl[tcp://10.0.1.200:4000,10.0.1.200,4000,
alive=100,id={-31 -103 29 40 72 82 66 -11 -122 116 -49 -123 -114 -110 -11 121
}, payload={-84 -19 0 5 115 114 0 50 111 ...(421)}, command={}, domain={68 69
70 65 85 76 84 95 67 ...(15)}, ] notify:true peer:NODE
Dec 16, 2007 9:28:16 AM org.codehaus.wadi.tribes.WadiMemberInterceptor
memberAdded
INFO: memberAdded:tcp://10.0.1.200:4000
Dec 16, 2007 9:28:16 AM org.apache.catalina.tribes.io.BufferPool getBufferPool
INFO: Created a buffer pool with max size:104857600 bytes of
type:org.apache.catalina.tribes.io.BufferPool15Impl
started in 2.373s
Module 44/59 org.apache.geronimo.configs/wadi-clustering/2.1-SNAPSHOT/car
started in .000s
Module 45/59 org.apache.geronimo.configs/uddi-jetty6/2.1-SNAPSHOT/car
started in .537s
Module 46/59 org.apache.geronimo.configs/axis/2.1-SNAPSHOT/car
started in .000s
Module 47/59 org.apache.geronimo.configs/axis-deployer/2.1-SNAPSHOT/car
started in .088s
Module 48/59 org.apache.geronimo.configs/j2ee-corba-yoko/2.1-SNAPSHOT/car
started in .932s
Module 49/59 org.apache.geronimo.configs/mejb/2.1-SNAPSHOT/car
started in .218s
Module 50/59
org.apache.geronimo.configs/jetty6-clustering-builder-wadi/2.1-SNAPSHOT/car
started in .037s
Module 51/59 org.apache.geronimo.configs/hot-deployer/2.1-SNAPSHOT/car
started in .645s
Module 52/59
org.apache.geronimo.configs/openejb-corba-deployer/2.1-SNAPSHOT/car
started in .135s
Module 53/59 org.apache.geronimo.configs/javamail/2.1-SNAPSHOT/car
started in .067s
Module 54/59 org.apache.geronimo.configs/cxf-deployer/2.1-SNAPSHOT/car
started in .045s
Module 55/59 org.apache.geronimo.configs/welcome-jetty/2.1-SNAPSHOT/car
started in .109s
Module 56/59 org.apache.geronimo.configs/sharedlib/2.1-SNAPSHOT/car
started in .013s
Module 57/59 org.apache.geronimo.configs/client-deployer/2.1-SNAPSHOT/car
started in .099s
Module 58/59 org.apache.geronimo.configs/cxf-ejb-deployer/2.1-SNAPSHOT/car
started in .066s
Module 59/59 org.apache.geronimo.plugins/plancreator-jetty/2.1-SNAPSHOT/car
started in .289s
Startup completed in 20.590s seconds
Listening on Ports:
0 0.0.0.0 Derby Connector
1050 127.0.0.1 CORBA Naming Service
1099 0.0.0.0 RMI Naming
2001 127.0.0.1 OpenEJB ORB Adapter
4201 0.0.0.0 OpenEJB Daemon
6882 127.0.0.1 OpenEJB ORB Adapter
8009 0.0.0.0 Jetty Connector AJP13
8080 0.0.0.0 Jetty SelectChannel Connector HTTP
8443 0.0.0.0 Jetty SelectChannel Connector HTTPS
9999 0.0.0.0 JMX Remoting Connector
61613 0.0.0.0 ActiveMQ Transport Connector
61616 0.0.0.0 ActiveMQ Transport Connector
Started Application Modules:
EAR: org.apache.geronimo.configs/uddi-jetty6/2.1-SNAPSHOT/car
EAR: org.apache.geronimo.plugins/console-jetty/2.1-SNAPSHOT/car
JAR: org.apache.geronimo.configs/mejb/2.1-SNAPSHOT/car
RAR: org.apache.geronimo.configs/activemq-ra/2.1-SNAPSHOT/car
RAR: org.apache.geronimo.configs/system-database/2.1-SNAPSHOT/car
WAR: org.apache.geronimo.configs/ca-helper-jetty/2.1-SNAPSHOT/car
WAR: org.apache.geronimo.configs/dojo-jetty6/2.1-SNAPSHOT/car
WAR: org.apache.geronimo.configs/remote-deploy-jetty/2.1-SNAPSHOT/car
WAR: org.apache.geronimo.configs/welcome-jetty/2.1-SNAPSHOT/car
WAR: org.apache.geronimo.plugins/activemq-jetty/2.1-SNAPSHOT/car
WAR: org.apache.geronimo.plugins/debugviews-jetty/2.1-SNAPSHOT/car
WAR: org.apache.geronimo.plugins/plancreator-jetty/2.1-SNAPSHOT/car
WAR: org.apache.geronimo.plugins/system-database-jetty/2.1-SNAPSHOT/car
Web Applications:
/
/CAHelper
/activemq
/console
/console-base
/debug-views
/dojo
/juddi
/plan-creator
/remote-deploy
/system-database
Geronimo Application Server started
C-c C-c[] received stop signal
09:28:26,400 WARN [BasicEnvelopeDispatcherManager] spurious message received:
Message: to [TribesPeer [NODE; tcp://10.0.1.200:4000]]; replyTo [TribesPeer
[NODE; tcp://10.0.1.200:4000]]; payload [Service [CommandEndPoint] in space
[WADI/Admin] hosted by [TribesPeer [NODE; tcp://10.0.1.200:4000]] is [STOPPING]]
09:28:26,400 WARN [BasicEnvelopeDispatcherManager] spurious message received:
Message: to [TribesPeer [NODE; tcp://10.0.1.200:4000]]; replyTo [TribesPeer
[NODE; tcp://10.0.1.200:4000]]; payload [Service [CommandEndPoint] in space
[WADI/Admin] hosted by [TribesPeer [NODE; tcp://10.0.1.200:4000]] is [STOPPED]]
Here's the exception stack trace I saw once on shutdown:
09:20:09,101 ERROR [TribesDispatcher] Interrupted when a TribesMessage
received, unable to hand it off to the thread pool.
java.lang.InterruptedException
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.offer(Unknown
Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.execute(Unknown
Source)
at
org.codehaus.wadi.group.impl.PooledExecutorAdapter.execute(PooledExecutorAdapter.java:40)
at
org.codehaus.wadi.tribes.TribesDispatcher.messageReceived(TribesDispatcher.java:102)
at
org.apache.catalina.tribes.group.GroupChannel.messageReceived(GroupChannel.java:264)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.messageReceived(ChannelInterceptorBase.java:79)
at
org.codehaus.wadi.tribes.WadiMemberInterceptor.messageReceived(WadiMemberInterceptor.java:58)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.messageReceived(ChannelInterceptorBase.java:79)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.messageReceived(ChannelInterceptorBase.java:79)
at
org.apache.catalina.tribes.group.interceptors.DomainFilterInterceptor.messageReceived(DomainFilterInterceptor.java:44)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.messageReceived(ChannelInterceptorBase.java:79)
at
org.apache.catalina.tribes.group.interceptors.TcpFailureDetector.messageReceived(TcpFailureDetector.java:110)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.messageReceived(ChannelInterceptorBase.java:79)
at
org.apache.catalina.tribes.group.ChannelCoordinator.messageReceived(ChannelCoordinator.java:241)
at
org.apache.catalina.tribes.transport.ReceiverBase.messageDataReceived(ReceiverBase.java:225)
at
org.apache.catalina.tribes.transport.nio.NioReplicationTask.drainChannel(NioReplicationTask.java:188)
at
org.apache.catalina.tribes.transport.nio.NioReplicationTask.run(NioReplicationTask.java:91)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:613)
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
