You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@tomee.apache.org by David Blevins <da...@gmail.com> on 2012/03/22 00:02:28 UTC
Slight overhaul of client code
I've been doing some work on the multipoint failover/clustering code. In the process I've done some major improvements to the client using an event pattern which has been proving to be a major help in logging and testing.
It's basically a trimmed version of CDI @Observes/fireEvent. Something I've been wanting to add to the server for a while, more so now seeing how well it works in the client. Something to hack on after a final release :)
Will post more details once it's ready to commit, in the meantime "head's up" and here's a small preview of the client log output below.
-David
Mar 21, 2012 3:38:51 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Starting red server
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
CONFIG: ClientVersion{version='4.0.0-beta-3-SNAPSHOT', date='20120320', time='09:34'}
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
INFO: RemoteInitialContextCreated{providerUri=ejbd://localhost:50397/red}
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
CONFIG: ConnectionFactoryAdded{scheme='default', factory=org.apache.openejb.client.SocketConnectionFactory}
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
CONFIG: ConnectionFactoryAdded{scheme='ejbd', factory=org.apache.openejb.client.SocketConnectionFactory}
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
CONFIG: ConnectionFactoryAdded{scheme='ejbds', factory=org.apache.openejb.client.SocketConnectionFactory}
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
CONFIG: ConnectionFactoryAdded{scheme='http', factory=org.apache.openejb.client.HttpConnectionFactory}
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
CONFIG: ConnectionFactoryAdded{scheme='https', factory=org.apache.openejb.client.HttpConnectionFactory}
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
CONFIG: ConnectionFactoryAdded{scheme='multicast', factory=org.apache.openejb.client.MulticastConnectionFactory}
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
CONFIG: ConnectionFactoryAdded{scheme='failover', factory=org.apache.openejb.client.FailoverConnectionFactory}
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
CONFIG: ConnectionStrategyAdded{scheme='sticky', strategy=org.apache.openejb.client.StickyConnectionStrategy}
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
CONFIG: ConnectionStrategyAdded{scheme='random', strategy=org.apache.openejb.client.RandomConnectionStrategy}
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
CONFIG: ConnectionStrategyAdded{scheme='roundrobin', strategy=org.apache.openejb.client.RoundRobinConnectionStrategy}
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
CONFIG: ConnectionStrategyAdded{scheme='round-robin', strategy=org.apache.openejb.client.RoundRobinConnectionStrategy}
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
CONFIG: ConnectionStrategyAdded{scheme='default', strategy=org.apache.openejb.client.StickyConnectionStrategy}
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
INFO: ConnectionOpened{uri=ejbd://localhost:50397/red}
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/red, version=1332369533612, uris=1}
Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/red, version=1332369533612, uris=1} #1 ejbd://localhost:50397/red
Mar 21, 2012 3:38:54 PM org.apache.openejb.server.discovery.MultipointServer$Session info
INFO: root:50393 < 50398 GREETING Session{uri=conn://127.0.0.1:50398/red, state=GREETING, owner=50393, s=50393, c=50402, server}@852713311 DISCOVERED
Mar 21, 2012 3:38:54 PM org.apache.openejb.server.discovery.Tracker fireServiceAddedEvent
INFO: Added Service{uri=ejb:ejbd://localhost:50397/red}
Mar 21, 2012 3:38:58 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Starting green server
Mar 21, 2012 3:39:00 PM org.apache.openejb.client.EventLogger log
INFO: RemoteInitialContextCreated{providerUri=ejbd://localhost:50403/green}
Mar 21, 2012 3:39:00 PM org.apache.openejb.client.EventLogger log
INFO: ConnectionOpened{uri=ejbd://localhost:50403/green}
Mar 21, 2012 3:39:00 PM org.apache.openejb.client.EventLogger log
FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50403/green, version=1332369540572, uris=1}
Mar 21, 2012 3:39:00 PM org.apache.openejb.client.EventLogger log
FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50403/green, version=1332369540572, uris=1} #1 ejbd://localhost:50403/green
Mar 21, 2012 3:39:01 PM org.apache.openejb.server.discovery.MultipointServer$Session info
INFO: root:50393 < 50404 GREETING Session{uri=conn://127.0.0.1:50404/green, state=GREETING, owner=50393, s=50393, c=50408, server}@141479621 DISCOVERED
Mar 21, 2012 3:39:01 PM org.apache.openejb.server.discovery.Tracker fireServiceAddedEvent
INFO: Added Service{uri=ejb:ejbd://localhost:50403/green}
Mar 21, 2012 3:39:04 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Starting blue server
Mar 21, 2012 3:39:06 PM org.apache.openejb.client.EventLogger log
INFO: RemoteInitialContextCreated{providerUri=ejbd://localhost:50410/blue}
Mar 21, 2012 3:39:06 PM org.apache.openejb.client.EventLogger log
INFO: ConnectionOpened{uri=ejbd://localhost:50410/blue}
Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50410/blue, version=1332369546976, uris=1}
Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50410/blue, version=1332369546976, uris=1} #1 ejbd://localhost:50410/blue
Mar 21, 2012 3:39:07 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Beginning Test
Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
INFO: RemoteInitialContextCreated{providerUri=ejbd://localhost:50397/provider}
Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
INFO: ConnectionOpened{uri=ejbd://localhost:50397/provider}
Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369541083, uris=2}
Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369541083, uris=2} #1 ejbd://localhost:50397/red
Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369541083, uris=2} #2 ejbd://localhost:50403/green
Mar 21, 2012 3:39:07 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Looping
Mar 21, 2012 3:39:07 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Sticky request to red
Mar 21, 2012 3:39:07 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Performing 1000 invocations, expecting red to be used for each invocation.
Mar 21, 2012 3:39:07 PM org.apache.openejb.server.discovery.MultipointServer$Session info
INFO: root:50393 < 50411 GREETING Session{uri=conn://127.0.0.1:50411/blue, state=GREETING, owner=50393, s=50393, c=50416, server}@888356977 DISCOVERED
Mar 21, 2012 3:39:07 PM org.apache.openejb.server.discovery.Tracker fireServiceAddedEvent
INFO: Added Service{uri=ejb:ejbd://localhost:50410/blue}
Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369547482, uris=3}
Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369547482, uris=3} #1 ejbd://localhost:50397/red
Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369547482, uris=3} #2 ejbd://localhost:50403/green
Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369547482, uris=3} #3 ejbd://localhost:50410/blue
Mar 21, 2012 3:39:07 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Shutting down red
Mar 21, 2012 3:39:08 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Looping
Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
SEVERE: RequestFailed{server=ejbd://localhost:50397/red} EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD, method='name', primaryKey='null'}
Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
INFO: RetryingRequest{server=ejbd://localhost:50397/provider} EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD, method='name', primaryKey='null'}
Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
WARNING: StickyFailover{remaining=1, failed=1, server=ejbd://localhost:50403/green}
Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369547485, uris=3}
Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369547485, uris=3} #1 ejbd://localhost:50403/green
Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369547485, uris=3} #2 ejbd://localhost:50397/red
Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369547485, uris=3} #3 ejbd://localhost:50410/blue
Mar 21, 2012 3:39:08 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Sticky request to green
Mar 21, 2012 3:39:08 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Performing 1000 invocations, expecting green to be used for each invocation.
Mar 21, 2012 3:39:09 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Shutting down green
Mar 21, 2012 3:39:09 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Looping
Mar 21, 2012 3:39:09 PM org.apache.openejb.client.EventLogger log
SEVERE: RequestFailed{server=ejbd://localhost:50403/green} EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD, method='name', primaryKey='null'}
Mar 21, 2012 3:39:09 PM org.apache.openejb.client.EventLogger log
INFO: RetryingRequest{server=ejbd://localhost:50397/provider} EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD, method='name', primaryKey='null'}
Mar 21, 2012 3:39:09 PM org.apache.openejb.client.EventLogger log
WARNING: StickyFailover{remaining=1, failed=1, server=ejbd://localhost:50397/red}
Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
SEVERE: ConnectionFailed{uri=ejbd://localhost:50397/red}
Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
WARNING: StickyFailover{remaining=0, failed=2, server=ejbd://localhost:50410/blue}
Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369547486, uris=3}
Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369547486, uris=3} #1 ejbd://localhost:50410/blue
Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369547486, uris=3} #2 ejbd://localhost:50397/red
Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369547486, uris=3} #3 ejbd://localhost:50403/green
Mar 21, 2012 3:39:10 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Sticky request to blue
Mar 21, 2012 3:39:10 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Performing 1000 invocations, expecting blue to be used for each invocation.
Mar 21, 2012 3:39:10 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Shutting down blue
Mar 21, 2012 3:39:11 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: All Servers Shutdown
Mar 21, 2012 3:39:11 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Making one last request, expecting complete failover
Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
SEVERE: RequestFailed{server=ejbd://localhost:50410/blue} EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD, method='name', primaryKey='null'}
Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
INFO: RetryingRequest{server=ejbd://localhost:50397/provider} EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD, method='name', primaryKey='null'}
Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
WARNING: StickyFailover{remaining=1, failed=1, server=ejbd://localhost:50397/red}
Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
SEVERE: ConnectionFailed{uri=ejbd://localhost:50397/red}
Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
WARNING: StickyFailover{remaining=0, failed=2, server=ejbd://localhost:50403/green}
Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
SEVERE: ConnectionFailed{uri=ejbd://localhost:50403/green}
Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
WARNING: BootstrappingConnection{provider=ejbd://localhost:50397/provider}
Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
SEVERE: RequestFailed{server=ejbd://localhost:50397/provider} EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD, method='name', primaryKey='null'}
Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
INFO: RetryingRequest{server=ejbd://localhost:50397/provider} EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD, method='name', primaryKey='null'}
Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
SEVERE: ConnectionStrategyFailed{strategy=StickyConnectionStrategy, cluster=org.apache.openejb.client.ClusterMetaData@53797795, server=ejbd://localhost:50397/provider}
Mar 21, 2012 3:39:11 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Pass. Request resulted in IOException: Unknown Container Exception: org.apache.openejb.client.RemoteFailoverException: Cannot complete request. Retry attempted on 4 servers; nested exception is:
java.io.IOException: Cannot write the request to the server:
Mar 21, 2012 3:39:11 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Starting blue server
Mar 21, 2012 3:39:12 PM org.apache.openejb.server.discovery.Tracker fireServiceRemovedEvent
INFO: Removed Service{uri=ejb:ejbd://localhost:50397/red}
Mar 21, 2012 3:39:13 PM org.apache.openejb.itest.failover.DedicatedRootServerTest test
INFO: Performing one more invocation
Mar 21, 2012 3:39:13 PM org.apache.openejb.client.EventLogger log
SEVERE: ConnectionFailed{uri=ejbd://localhost:50397/provider}
Mar 21, 2012 3:39:13 PM org.apache.openejb.client.EventLogger log
WARNING: StickyFailover{remaining=2, failed=0, server=ejbd://localhost:50410/blue}
Mar 21, 2012 3:39:13 PM org.apache.openejb.client.EventLogger log
INFO: ConnectionOpened{uri=ejbd://localhost:50410/blue}
Mar 21, 2012 3:39:13 PM org.apache.openejb.client.EventLogger log
FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369553559, uris=1}
Mar 21, 2012 3:39:13 PM org.apache.openejb.client.EventLogger log
FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider, version=1332369553559, uris=1} #1 ejbd://localhost:50410/blue
Re: Slight overhaul of client code
Posted by David Blevins <da...@gmail.com>.
On Mar 21, 2012, at 4:53 PM, Romain Manni-Bucau wrote:
> Fotr the log we should be able to do so using a custom logger.
Feel free to hack one up!
-David
>
> Le 22 mars 2012 00:46, "David Blevins" <da...@gmail.com> a écrit :
>
>
> On Mar 21, 2012, at 4:14 PM, Romain Manni-Bucau wrote:
>
>> Great, i like this feature!
>>
>> regardin...
> If you know how to do that, I'd love to add it. Here's the code:
>
> https://gist.github.com/2154192
>
>
>>
>> is it easy to register an observer? couldn't we use cdi?
> Yep. There's a method on the Client object which does it. For the server
> itself using CDI would definitely be preferable. So far, this tiny class
> has all the client needs:
>
> https://gist.github.com/2154225
>
>
> -David
>
>
>> 2012/3/22 David Blevins <da...@gmail.com>
>>
>>> I've been doing some work on the multipoi...
Re: Slight overhaul of client code
Posted by Romain Manni-Bucau <rm...@gmail.com>.
Fotr the log we should be able to do so using a custom logger.
Otherwise that's cool!
- Romain
Le 22 mars 2012 00:46, "David Blevins" <da...@gmail.com> a écrit :
On Mar 21, 2012, at 4:14 PM, Romain Manni-Bucau wrote:
> Great, i like this feature!
>
> regardin...
If you know how to do that, I'd love to add it. Here's the code:
https://gist.github.com/2154192
>
> is it easy to register an observer? couldn't we use cdi?
Yep. There's a method on the Client object which does it. For the server
itself using CDI would definitely be preferable. So far, this tiny class
has all the client needs:
https://gist.github.com/2154225
-David
> 2012/3/22 David Blevins <da...@gmail.com>
>
>> I've been doing some work on the multipoi...
Re: Slight overhaul of client code
Posted by David Blevins <da...@gmail.com>.
On Mar 21, 2012, at 4:14 PM, Romain Manni-Bucau wrote:
> Great, i like this feature!
>
> regarding logs couldn't "org.apache.openejb.client.EventLogger" be replaced
> by the source of the event?
If you know how to do that, I'd love to add it. Here's the code:
https://gist.github.com/2154192
>
> is it easy to register an observer? couldn't we use cdi?
Yep. There's a method on the Client object which does it. For the server itself using CDI would definitely be preferable. So far, this tiny class has all the client needs:
https://gist.github.com/2154225
-David
> 2012/3/22 David Blevins <da...@gmail.com>
>
>> I've been doing some work on the multipoint failover/clustering code. In
>> the process I've done some major improvements to the client using an event
>> pattern which has been proving to be a major help in logging and testing.
>>
>> It's basically a trimmed version of CDI @Observes/fireEvent. Something
>> I've been wanting to add to the server for a while, more so now seeing how
>> well it works in the client. Something to hack on after a final release :)
>>
>> Will post more details once it's ready to commit, in the meantime "head's
>> up" and here's a small preview of the client log output below.
>>
>>
>> -David
>>
>> Mar 21, 2012 3:38:51 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Starting red server
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> CONFIG: ClientVersion{version='4.0.0-beta-3-SNAPSHOT', date='20120320',
>> time='09:34'}
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> INFO: RemoteInitialContextCreated{providerUri=ejbd://localhost:50397/red}
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> CONFIG: ConnectionFactoryAdded{scheme='default',
>> factory=org.apache.openejb.client.SocketConnectionFactory}
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> CONFIG: ConnectionFactoryAdded{scheme='ejbd',
>> factory=org.apache.openejb.client.SocketConnectionFactory}
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> CONFIG: ConnectionFactoryAdded{scheme='ejbds',
>> factory=org.apache.openejb.client.SocketConnectionFactory}
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> CONFIG: ConnectionFactoryAdded{scheme='http',
>> factory=org.apache.openejb.client.HttpConnectionFactory}
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> CONFIG: ConnectionFactoryAdded{scheme='https',
>> factory=org.apache.openejb.client.HttpConnectionFactory}
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> CONFIG: ConnectionFactoryAdded{scheme='multicast',
>> factory=org.apache.openejb.client.MulticastConnectionFactory}
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> CONFIG: ConnectionFactoryAdded{scheme='failover',
>> factory=org.apache.openejb.client.FailoverConnectionFactory}
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> CONFIG: ConnectionStrategyAdded{scheme='sticky',
>> strategy=org.apache.openejb.client.StickyConnectionStrategy}
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> CONFIG: ConnectionStrategyAdded{scheme='random',
>> strategy=org.apache.openejb.client.RandomConnectionStrategy}
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> CONFIG: ConnectionStrategyAdded{scheme='roundrobin',
>> strategy=org.apache.openejb.client.RoundRobinConnectionStrategy}
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> CONFIG: ConnectionStrategyAdded{scheme='round-robin',
>> strategy=org.apache.openejb.client.RoundRobinConnectionStrategy}
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> CONFIG: ConnectionStrategyAdded{scheme='default',
>> strategy=org.apache.openejb.client.StickyConnectionStrategy}
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> INFO: ConnectionOpened{uri=ejbd://localhost:50397/red}
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/red,
>> version=1332369533612, uris=1}
>> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
>> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/red,
>> version=1332369533612, uris=1} #1 ejbd://localhost:50397/red
>> Mar 21, 2012 3:38:54 PM
>> org.apache.openejb.server.discovery.MultipointServer$Session info
>> INFO: root:50393 < 50398 GREETING Session{uri=conn://127.0.0.1:50398/red,
>> state=GREETING, owner=50393, s=50393, c=50402, server}@852713311DISCOVERED
>> Mar 21, 2012 3:38:54 PM org.apache.openejb.server.discovery.Tracker
>> fireServiceAddedEvent
>> INFO: Added Service{uri=ejb:ejbd://localhost:50397/red}
>> Mar 21, 2012 3:38:58 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Starting green server
>> Mar 21, 2012 3:39:00 PM org.apache.openejb.client.EventLogger log
>> INFO: RemoteInitialContextCreated{providerUri=ejbd://localhost:50403/green}
>> Mar 21, 2012 3:39:00 PM org.apache.openejb.client.EventLogger log
>> INFO: ConnectionOpened{uri=ejbd://localhost:50403/green}
>> Mar 21, 2012 3:39:00 PM org.apache.openejb.client.EventLogger log
>> FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50403/green,
>> version=1332369540572, uris=1}
>> Mar 21, 2012 3:39:00 PM org.apache.openejb.client.EventLogger log
>> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50403/green,
>> version=1332369540572, uris=1} #1 ejbd://localhost:50403/green
>> Mar 21, 2012 3:39:01 PM
>> org.apache.openejb.server.discovery.MultipointServer$Session info
>> INFO: root:50393 < 50404 GREETING Session{uri=conn://127.0.0.1:50404/green,
>> state=GREETING, owner=50393, s=50393, c=50408, server}@141479621DISCOVERED
>> Mar 21, 2012 3:39:01 PM org.apache.openejb.server.discovery.Tracker
>> fireServiceAddedEvent
>> INFO: Added Service{uri=ejb:ejbd://localhost:50403/green}
>> Mar 21, 2012 3:39:04 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Starting blue server
>> Mar 21, 2012 3:39:06 PM org.apache.openejb.client.EventLogger log
>> INFO: RemoteInitialContextCreated{providerUri=ejbd://localhost:50410/blue}
>> Mar 21, 2012 3:39:06 PM org.apache.openejb.client.EventLogger log
>> INFO: ConnectionOpened{uri=ejbd://localhost:50410/blue}
>> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
>> FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50410/blue,
>> version=1332369546976, uris=1}
>> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
>> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50410/blue,
>> version=1332369546976, uris=1} #1 ejbd://localhost:50410/blue
>> Mar 21, 2012 3:39:07 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Beginning Test
>> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
>> INFO:
>> RemoteInitialContextCreated{providerUri=ejbd://localhost:50397/provider}
>> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
>> INFO: ConnectionOpened{uri=ejbd://localhost:50397/provider}
>> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
>> FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369541083, uris=2}
>> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
>> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369541083, uris=2} #1 ejbd://localhost:50397/red
>> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
>> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369541083, uris=2} #2 ejbd://localhost:50403/green
>> Mar 21, 2012 3:39:07 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Looping
>> Mar 21, 2012 3:39:07 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Sticky request to red
>> Mar 21, 2012 3:39:07 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Performing 1000 invocations, expecting red to be used for each
>> invocation.
>> Mar 21, 2012 3:39:07 PM
>> org.apache.openejb.server.discovery.MultipointServer$Session info
>> INFO: root:50393 < 50411 GREETING Session{uri=conn://127.0.0.1:50411/blue,
>> state=GREETING, owner=50393, s=50393, c=50416, server}@888356977DISCOVERED
>> Mar 21, 2012 3:39:07 PM org.apache.openejb.server.discovery.Tracker
>> fireServiceAddedEvent
>> INFO: Added Service{uri=ejb:ejbd://localhost:50410/blue}
>> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
>> FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369547482, uris=3}
>> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
>> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369547482, uris=3} #1 ejbd://localhost:50397/red
>> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
>> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369547482, uris=3} #2 ejbd://localhost:50403/green
>> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
>> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369547482, uris=3} #3 ejbd://localhost:50410/blue
>> Mar 21, 2012 3:39:07 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Shutting down red
>> Mar 21, 2012 3:39:08 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Looping
>> Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
>> SEVERE: RequestFailed{server=ejbd://localhost:50397/red}
>> EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD,
>> method='name', primaryKey='null'}
>> Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
>> INFO: RetryingRequest{server=ejbd://localhost:50397/provider}
>> EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD,
>> method='name', primaryKey='null'}
>> Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
>> WARNING: StickyFailover{remaining=1, failed=1,
>> server=ejbd://localhost:50403/green}
>> Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
>> FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369547485, uris=3}
>> Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
>> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369547485, uris=3} #1 ejbd://localhost:50403/green
>> Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
>> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369547485, uris=3} #2 ejbd://localhost:50397/red
>> Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
>> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369547485, uris=3} #3 ejbd://localhost:50410/blue
>> Mar 21, 2012 3:39:08 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Sticky request to green
>> Mar 21, 2012 3:39:08 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Performing 1000 invocations, expecting green to be used for each
>> invocation.
>> Mar 21, 2012 3:39:09 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Shutting down green
>> Mar 21, 2012 3:39:09 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Looping
>> Mar 21, 2012 3:39:09 PM org.apache.openejb.client.EventLogger log
>> SEVERE: RequestFailed{server=ejbd://localhost:50403/green}
>> EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD,
>> method='name', primaryKey='null'}
>> Mar 21, 2012 3:39:09 PM org.apache.openejb.client.EventLogger log
>> INFO: RetryingRequest{server=ejbd://localhost:50397/provider}
>> EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD,
>> method='name', primaryKey='null'}
>> Mar 21, 2012 3:39:09 PM org.apache.openejb.client.EventLogger log
>> WARNING: StickyFailover{remaining=1, failed=1,
>> server=ejbd://localhost:50397/red}
>> Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
>> SEVERE: ConnectionFailed{uri=ejbd://localhost:50397/red}
>> Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
>> WARNING: StickyFailover{remaining=0, failed=2,
>> server=ejbd://localhost:50410/blue}
>> Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
>> FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369547486, uris=3}
>> Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
>> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369547486, uris=3} #1 ejbd://localhost:50410/blue
>> Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
>> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369547486, uris=3} #2 ejbd://localhost:50397/red
>> Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
>> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369547486, uris=3} #3 ejbd://localhost:50403/green
>> Mar 21, 2012 3:39:10 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Sticky request to blue
>> Mar 21, 2012 3:39:10 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Performing 1000 invocations, expecting blue to be used for each
>> invocation.
>> Mar 21, 2012 3:39:10 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Shutting down blue
>> Mar 21, 2012 3:39:11 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: All Servers Shutdown
>> Mar 21, 2012 3:39:11 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Making one last request, expecting complete failover
>> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
>> SEVERE: RequestFailed{server=ejbd://localhost:50410/blue}
>> EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD,
>> method='name', primaryKey='null'}
>> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
>> INFO: RetryingRequest{server=ejbd://localhost:50397/provider}
>> EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD,
>> method='name', primaryKey='null'}
>> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
>> WARNING: StickyFailover{remaining=1, failed=1,
>> server=ejbd://localhost:50397/red}
>> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
>> SEVERE: ConnectionFailed{uri=ejbd://localhost:50397/red}
>> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
>> WARNING: StickyFailover{remaining=0, failed=2,
>> server=ejbd://localhost:50403/green}
>> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
>> SEVERE: ConnectionFailed{uri=ejbd://localhost:50403/green}
>> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
>> WARNING: BootstrappingConnection{provider=ejbd://localhost:50397/provider}
>> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
>> SEVERE: RequestFailed{server=ejbd://localhost:50397/provider}
>> EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD,
>> method='name', primaryKey='null'}
>> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
>> INFO: RetryingRequest{server=ejbd://localhost:50397/provider}
>> EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD,
>> method='name', primaryKey='null'}
>> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
>> SEVERE: ConnectionStrategyFailed{strategy=StickyConnectionStrategy,
>> cluster=org.apache.openejb.client.ClusterMetaData@53797795,
>> server=ejbd://localhost:50397/provider}
>> Mar 21, 2012 3:39:11 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Pass. Request resulted in IOException: Unknown Container Exception:
>> org.apache.openejb.client.RemoteFailoverException: Cannot complete request.
>> Retry attempted on 4 servers; nested exception is:
>> java.io.IOException: Cannot write the request to the server:
>> Mar 21, 2012 3:39:11 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Starting blue server
>> Mar 21, 2012 3:39:12 PM org.apache.openejb.server.discovery.Tracker
>> fireServiceRemovedEvent
>> INFO: Removed Service{uri=ejb:ejbd://localhost:50397/red}
>> Mar 21, 2012 3:39:13 PM
>> org.apache.openejb.itest.failover.DedicatedRootServerTest test
>> INFO: Performing one more invocation
>> Mar 21, 2012 3:39:13 PM org.apache.openejb.client.EventLogger log
>> SEVERE: ConnectionFailed{uri=ejbd://localhost:50397/provider}
>> Mar 21, 2012 3:39:13 PM org.apache.openejb.client.EventLogger log
>> WARNING: StickyFailover{remaining=2, failed=0,
>> server=ejbd://localhost:50410/blue}
>> Mar 21, 2012 3:39:13 PM org.apache.openejb.client.EventLogger log
>> INFO: ConnectionOpened{uri=ejbd://localhost:50410/blue}
>> Mar 21, 2012 3:39:13 PM org.apache.openejb.client.EventLogger log
>> FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369553559, uris=1}
>> Mar 21, 2012 3:39:13 PM org.apache.openejb.client.EventLogger log
>> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
>> version=1332369553559, uris=1} #1 ejbd://localhost:50410/blue
>>
>>
Re: Slight overhaul of client code
Posted by Romain Manni-Bucau <rm...@gmail.com>.
Great, i like this feature!
regarding logs couldn't "org.apache.openejb.client.EventLogger" be replaced
by the source of the event?
is it easy to register an observer? couldn't we use cdi?
- Romain
2012/3/22 David Blevins <da...@gmail.com>
> I've been doing some work on the multipoint failover/clustering code. In
> the process I've done some major improvements to the client using an event
> pattern which has been proving to be a major help in logging and testing.
>
> It's basically a trimmed version of CDI @Observes/fireEvent. Something
> I've been wanting to add to the server for a while, more so now seeing how
> well it works in the client. Something to hack on after a final release :)
>
> Will post more details once it's ready to commit, in the meantime "head's
> up" and here's a small preview of the client log output below.
>
>
> -David
>
> Mar 21, 2012 3:38:51 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Starting red server
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> CONFIG: ClientVersion{version='4.0.0-beta-3-SNAPSHOT', date='20120320',
> time='09:34'}
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> INFO: RemoteInitialContextCreated{providerUri=ejbd://localhost:50397/red}
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> CONFIG: ConnectionFactoryAdded{scheme='default',
> factory=org.apache.openejb.client.SocketConnectionFactory}
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> CONFIG: ConnectionFactoryAdded{scheme='ejbd',
> factory=org.apache.openejb.client.SocketConnectionFactory}
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> CONFIG: ConnectionFactoryAdded{scheme='ejbds',
> factory=org.apache.openejb.client.SocketConnectionFactory}
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> CONFIG: ConnectionFactoryAdded{scheme='http',
> factory=org.apache.openejb.client.HttpConnectionFactory}
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> CONFIG: ConnectionFactoryAdded{scheme='https',
> factory=org.apache.openejb.client.HttpConnectionFactory}
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> CONFIG: ConnectionFactoryAdded{scheme='multicast',
> factory=org.apache.openejb.client.MulticastConnectionFactory}
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> CONFIG: ConnectionFactoryAdded{scheme='failover',
> factory=org.apache.openejb.client.FailoverConnectionFactory}
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> CONFIG: ConnectionStrategyAdded{scheme='sticky',
> strategy=org.apache.openejb.client.StickyConnectionStrategy}
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> CONFIG: ConnectionStrategyAdded{scheme='random',
> strategy=org.apache.openejb.client.RandomConnectionStrategy}
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> CONFIG: ConnectionStrategyAdded{scheme='roundrobin',
> strategy=org.apache.openejb.client.RoundRobinConnectionStrategy}
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> CONFIG: ConnectionStrategyAdded{scheme='round-robin',
> strategy=org.apache.openejb.client.RoundRobinConnectionStrategy}
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> CONFIG: ConnectionStrategyAdded{scheme='default',
> strategy=org.apache.openejb.client.StickyConnectionStrategy}
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> INFO: ConnectionOpened{uri=ejbd://localhost:50397/red}
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/red,
> version=1332369533612, uris=1}
> Mar 21, 2012 3:38:53 PM org.apache.openejb.client.EventLogger log
> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/red,
> version=1332369533612, uris=1} #1 ejbd://localhost:50397/red
> Mar 21, 2012 3:38:54 PM
> org.apache.openejb.server.discovery.MultipointServer$Session info
> INFO: root:50393 < 50398 GREETING Session{uri=conn://127.0.0.1:50398/red,
> state=GREETING, owner=50393, s=50393, c=50402, server}@852713311DISCOVERED
> Mar 21, 2012 3:38:54 PM org.apache.openejb.server.discovery.Tracker
> fireServiceAddedEvent
> INFO: Added Service{uri=ejb:ejbd://localhost:50397/red}
> Mar 21, 2012 3:38:58 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Starting green server
> Mar 21, 2012 3:39:00 PM org.apache.openejb.client.EventLogger log
> INFO: RemoteInitialContextCreated{providerUri=ejbd://localhost:50403/green}
> Mar 21, 2012 3:39:00 PM org.apache.openejb.client.EventLogger log
> INFO: ConnectionOpened{uri=ejbd://localhost:50403/green}
> Mar 21, 2012 3:39:00 PM org.apache.openejb.client.EventLogger log
> FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50403/green,
> version=1332369540572, uris=1}
> Mar 21, 2012 3:39:00 PM org.apache.openejb.client.EventLogger log
> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50403/green,
> version=1332369540572, uris=1} #1 ejbd://localhost:50403/green
> Mar 21, 2012 3:39:01 PM
> org.apache.openejb.server.discovery.MultipointServer$Session info
> INFO: root:50393 < 50404 GREETING Session{uri=conn://127.0.0.1:50404/green,
> state=GREETING, owner=50393, s=50393, c=50408, server}@141479621DISCOVERED
> Mar 21, 2012 3:39:01 PM org.apache.openejb.server.discovery.Tracker
> fireServiceAddedEvent
> INFO: Added Service{uri=ejb:ejbd://localhost:50403/green}
> Mar 21, 2012 3:39:04 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Starting blue server
> Mar 21, 2012 3:39:06 PM org.apache.openejb.client.EventLogger log
> INFO: RemoteInitialContextCreated{providerUri=ejbd://localhost:50410/blue}
> Mar 21, 2012 3:39:06 PM org.apache.openejb.client.EventLogger log
> INFO: ConnectionOpened{uri=ejbd://localhost:50410/blue}
> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
> FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50410/blue,
> version=1332369546976, uris=1}
> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50410/blue,
> version=1332369546976, uris=1} #1 ejbd://localhost:50410/blue
> Mar 21, 2012 3:39:07 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Beginning Test
> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
> INFO:
> RemoteInitialContextCreated{providerUri=ejbd://localhost:50397/provider}
> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
> INFO: ConnectionOpened{uri=ejbd://localhost:50397/provider}
> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
> FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369541083, uris=2}
> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369541083, uris=2} #1 ejbd://localhost:50397/red
> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369541083, uris=2} #2 ejbd://localhost:50403/green
> Mar 21, 2012 3:39:07 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Looping
> Mar 21, 2012 3:39:07 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Sticky request to red
> Mar 21, 2012 3:39:07 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Performing 1000 invocations, expecting red to be used for each
> invocation.
> Mar 21, 2012 3:39:07 PM
> org.apache.openejb.server.discovery.MultipointServer$Session info
> INFO: root:50393 < 50411 GREETING Session{uri=conn://127.0.0.1:50411/blue,
> state=GREETING, owner=50393, s=50393, c=50416, server}@888356977DISCOVERED
> Mar 21, 2012 3:39:07 PM org.apache.openejb.server.discovery.Tracker
> fireServiceAddedEvent
> INFO: Added Service{uri=ejb:ejbd://localhost:50410/blue}
> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
> FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369547482, uris=3}
> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369547482, uris=3} #1 ejbd://localhost:50397/red
> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369547482, uris=3} #2 ejbd://localhost:50403/green
> Mar 21, 2012 3:39:07 PM org.apache.openejb.client.EventLogger log
> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369547482, uris=3} #3 ejbd://localhost:50410/blue
> Mar 21, 2012 3:39:07 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Shutting down red
> Mar 21, 2012 3:39:08 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Looping
> Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
> SEVERE: RequestFailed{server=ejbd://localhost:50397/red}
> EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD,
> method='name', primaryKey='null'}
> Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
> INFO: RetryingRequest{server=ejbd://localhost:50397/provider}
> EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD,
> method='name', primaryKey='null'}
> Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
> WARNING: StickyFailover{remaining=1, failed=1,
> server=ejbd://localhost:50403/green}
> Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
> FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369547485, uris=3}
> Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369547485, uris=3} #1 ejbd://localhost:50403/green
> Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369547485, uris=3} #2 ejbd://localhost:50397/red
> Mar 21, 2012 3:39:08 PM org.apache.openejb.client.EventLogger log
> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369547485, uris=3} #3 ejbd://localhost:50410/blue
> Mar 21, 2012 3:39:08 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Sticky request to green
> Mar 21, 2012 3:39:08 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Performing 1000 invocations, expecting green to be used for each
> invocation.
> Mar 21, 2012 3:39:09 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Shutting down green
> Mar 21, 2012 3:39:09 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Looping
> Mar 21, 2012 3:39:09 PM org.apache.openejb.client.EventLogger log
> SEVERE: RequestFailed{server=ejbd://localhost:50403/green}
> EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD,
> method='name', primaryKey='null'}
> Mar 21, 2012 3:39:09 PM org.apache.openejb.client.EventLogger log
> INFO: RetryingRequest{server=ejbd://localhost:50397/provider}
> EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD,
> method='name', primaryKey='null'}
> Mar 21, 2012 3:39:09 PM org.apache.openejb.client.EventLogger log
> WARNING: StickyFailover{remaining=1, failed=1,
> server=ejbd://localhost:50397/red}
> Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
> SEVERE: ConnectionFailed{uri=ejbd://localhost:50397/red}
> Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
> WARNING: StickyFailover{remaining=0, failed=2,
> server=ejbd://localhost:50410/blue}
> Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
> FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369547486, uris=3}
> Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369547486, uris=3} #1 ejbd://localhost:50410/blue
> Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369547486, uris=3} #2 ejbd://localhost:50397/red
> Mar 21, 2012 3:39:10 PM org.apache.openejb.client.EventLogger log
> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369547486, uris=3} #3 ejbd://localhost:50403/green
> Mar 21, 2012 3:39:10 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Sticky request to blue
> Mar 21, 2012 3:39:10 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Performing 1000 invocations, expecting blue to be used for each
> invocation.
> Mar 21, 2012 3:39:10 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Shutting down blue
> Mar 21, 2012 3:39:11 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: All Servers Shutdown
> Mar 21, 2012 3:39:11 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Making one last request, expecting complete failover
> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
> SEVERE: RequestFailed{server=ejbd://localhost:50410/blue}
> EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD,
> method='name', primaryKey='null'}
> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
> INFO: RetryingRequest{server=ejbd://localhost:50397/provider}
> EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD,
> method='name', primaryKey='null'}
> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
> WARNING: StickyFailover{remaining=1, failed=1,
> server=ejbd://localhost:50397/red}
> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
> SEVERE: ConnectionFailed{uri=ejbd://localhost:50397/red}
> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
> WARNING: StickyFailover{remaining=0, failed=2,
> server=ejbd://localhost:50403/green}
> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
> SEVERE: ConnectionFailed{uri=ejbd://localhost:50403/green}
> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
> WARNING: BootstrappingConnection{provider=ejbd://localhost:50397/provider}
> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
> SEVERE: RequestFailed{server=ejbd://localhost:50397/provider}
> EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD,
> method='name', primaryKey='null'}
> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
> INFO: RetryingRequest{server=ejbd://localhost:50397/provider}
> EJBRequest{deploymentId='CalculatorBean', type=EJB_OBJECT_BUSINESS_METHOD,
> method='name', primaryKey='null'}
> Mar 21, 2012 3:39:11 PM org.apache.openejb.client.EventLogger log
> SEVERE: ConnectionStrategyFailed{strategy=StickyConnectionStrategy,
> cluster=org.apache.openejb.client.ClusterMetaData@53797795,
> server=ejbd://localhost:50397/provider}
> Mar 21, 2012 3:39:11 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Pass. Request resulted in IOException: Unknown Container Exception:
> org.apache.openejb.client.RemoteFailoverException: Cannot complete request.
> Retry attempted on 4 servers; nested exception is:
> java.io.IOException: Cannot write the request to the server:
> Mar 21, 2012 3:39:11 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Starting blue server
> Mar 21, 2012 3:39:12 PM org.apache.openejb.server.discovery.Tracker
> fireServiceRemovedEvent
> INFO: Removed Service{uri=ejb:ejbd://localhost:50397/red}
> Mar 21, 2012 3:39:13 PM
> org.apache.openejb.itest.failover.DedicatedRootServerTest test
> INFO: Performing one more invocation
> Mar 21, 2012 3:39:13 PM org.apache.openejb.client.EventLogger log
> SEVERE: ConnectionFailed{uri=ejbd://localhost:50397/provider}
> Mar 21, 2012 3:39:13 PM org.apache.openejb.client.EventLogger log
> WARNING: StickyFailover{remaining=2, failed=0,
> server=ejbd://localhost:50410/blue}
> Mar 21, 2012 3:39:13 PM org.apache.openejb.client.EventLogger log
> INFO: ConnectionOpened{uri=ejbd://localhost:50410/blue}
> Mar 21, 2012 3:39:13 PM org.apache.openejb.client.EventLogger log
> FINE: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369553559, uris=1}
> Mar 21, 2012 3:39:13 PM org.apache.openejb.client.EventLogger log
> FINER: ClusterMetaDataUpdated{provider=ejbd://localhost:50397/provider,
> version=1332369553559, uris=1} #1 ejbd://localhost:50410/blue
>
>