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 <[email protected]> > >> 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 >> >>
