activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Dain Sundstrom <d...@iq80.com>
Subject Re: Reply to message not being recieved...
Date Sat, 03 Mar 2007 16:21:47 GMT
I added the mx4j tools jar and the first jmx related exception went  
away, but now I'm getting this:

java.rmi.server.ExportException: internal error: ObjID already in use
	at sun.rmi.transport.ObjectTable.putTarget(ObjectTable.java:169)
	at sun.rmi.transport.Transport.exportObject(Transport.java:75)
	at sun.rmi.transport.tcp.TCPTransport.exportObject(TCPTransport.java: 
196)
	at sun.rmi.transport.tcp.TCPEndpoint.exportObject(TCPEndpoint.java:382)
	at sun.rmi.transport.LiveRef.exportObject(LiveRef.java:116)
	at sun.rmi.server.UnicastServerRef.exportObject 
(UnicastServerRef.java:180)
	at sun.rmi.registry.RegistryImpl.setup(RegistryImpl.java:92)
	at sun.rmi.registry.RegistryImpl.<init>(RegistryImpl.java:78)
	at java.rmi.registry.LocateRegistry.createRegistry 
(LocateRegistry.java:186)
	at org.apache.activemq.broker.jmx.ManagementContext.createConnector 
(ManagementContext.java:382)
	at org.apache.activemq.broker.jmx.ManagementContext.findMBeanServer 
(ManagementContext.java:301)
	at org.apache.activemq.broker.jmx.ManagementContext.getMBeanServer 
(ManagementContext.java:154)
	at org.apache.activemq.broker.BrokerService.createRegionBroker 
(BrokerService.java:1265)
	at org.apache.activemq.broker.BrokerService.createBroker 
(BrokerService.java:1209)
	at org.apache.activemq.broker.BrokerService.getBroker 
(BrokerService.java:508)
	at org.apache.activemq.broker.BrokerService.addConnector 
(BrokerService.java:163)
	at org.apache.activemq.broker.DefaultBrokerFactory.createBroker 
(DefaultBrokerFactory.java:55)
	at org.apache.activemq.broker.BrokerFactory.createBroker 
(BrokerFactory.java:57)
	at org.apache.activemq.ra.ActiveMQResourceAdapter.start 
(ActiveMQResourceAdapter.java:80)
	at org.apache.openejb.assembler.classic.Assembler.createResource 
(Assembler.java:735)


Looking around in openejb I don't see any place that is trying to  
initialize an RMI registry so I assume amq is trying to do it twice.   
I'd debug this in the java.rmi code, but unfortunately the Apple  
debugger in java 1.5.0_06 hangs (I'm waiting for a patch from  
apple).  Is there any obvious way to tell from the log I posted  
earlier if AMQ is starting two brokers or two somethings that  
initialize JMX?

-dain

On Mar 3, 2007, at 1:22 AM, James Strachan wrote:

> A good way to track down these kinds of issues is to look in  
> JConsole...
> http://activemq.apache.org/jmx.html
>
> which should display what connections & consumers are available, what
> their prefetch buffers are looking like and the status of the various
> destinations etc. It may be you've got a rogue consumer or something
>
>
> On 3/3/07, Dain Sundstrom <dain@iq80.com> wrote:
>> I have this test case in OpenEJB for our MDB container.  The junit
>> test sends a message to an MDB and the MDB sends a response message
>> to the junit test using the reply to (temp) queue in the request
>> message.  I've mocked up the architecture using an the RA in a
>> separate test case and it works perfectly, but for some reason when I
>> test the real container, it the reply message never makes it to the
>> client.  I can't spot the different between the two code bases, so
>> I'm hoping that one of you will be able to see the problem using the
>> test log.  The ****ed messages in the log are my messages from my
>> test code.  I'd post the code, but it's generic ejb container code,
>> so not much help.
>>
>> I appreciate any help
>>
>> -dain
>>
>> 18:30:43,935 INFO  [BrokerService] ActiveMQ 4.1.0-incubator JMS
>> Message Broker (localhost) is starting
>> 18:30:43,936 INFO  [BrokerService] For help or more information
>> please see: http://incubator.apache.org/activemq/
>> 18:30:44,761 INFO  [JDBCPersistenceAdapter] Database driver
>> recognized: [apache_derby_embedded_jdbc_driver]
>> 18:30:45,320 DEBUG [DefaultJDBCAdapter] Executing SQL: CREATE TABLE
>> ACTIVEMQ_MSGS(ID INTEGER NOT NULL, CONTAINER VARCHAR(250), MSGID_PROD
>> VARCHAR(250), MSGID_SEQ INTEGER, EXPIRATION BIGINT, MSG BLOB, PRIMARY
>> KEY ( ID ) )
>> 18:30:45,375 DEBUG [DefaultJDBCAdapter] Could not create JDBC tables;
>> The message table already existed. Failure was: CREATE TABLE
>> ACTIVEMQ_MSGS(ID INTEGER NOT NULL, CONTAINER VARCHAR(250), MSGID_PROD
>> VARCHAR(250), MSGID_SEQ INTEGER, EXPIRATION BIGINT, MSG BLOB, PRIMARY
>> KEY ( ID ) ) Message: Table/View 'ACTIVEMQ_MSGS' already exists in
>> Schema 'APP'. SQLState: X0Y32 Vendor code: 20000
>> 18:30:45,385 DEBUG [DefaultJDBCAdapter] Executing SQL: CREATE INDEX
>> ACTIVEMQ_MSGS_MIDX ON ACTIVEMQ_MSGS (MSGID_PROD,MSGID_SEQ)
>> 18:30:45,440 DEBUG [DefaultJDBCAdapter] Executing SQL: CREATE INDEX
>> ACTIVEMQ_MSGS_CIDX ON ACTIVEMQ_MSGS (CONTAINER)
>> 18:30:45,455 DEBUG [DefaultJDBCAdapter] Executing SQL: CREATE INDEX
>> ACTIVEMQ_MSGS_EIDX ON ACTIVEMQ_MSGS (EXPIRATION)
>> 18:30:45,469 DEBUG [DefaultJDBCAdapter] Executing SQL: CREATE TABLE
>> ACTIVEMQ_ACKS(CONTAINER VARCHAR(250) NOT NULL, CLIENT_ID VARCHAR(250)
>> NOT NULL, SUB_NAME VARCHAR(250) NOT NULL, SELECTOR VARCHAR(250),
>> LAST_ACKED_ID INTEGER, PRIMARY KEY ( CONTAINER, CLIENT_ID, SUB_NAME))
>> 18:30:45,482 DEBUG [DefaultJDBCAdapter] Could not create JDBC tables;
>> The message table already existed. Failure was: CREATE TABLE
>> ACTIVEMQ_ACKS(CONTAINER VARCHAR(250) NOT NULL, CLIENT_ID VARCHAR(250)
>> NOT NULL, SUB_NAME VARCHAR(250) NOT NULL, SELECTOR VARCHAR(250),
>> LAST_ACKED_ID INTEGER, PRIMARY KEY ( CONTAINER, CLIENT_ID, SUB_NAME))
>> Message: Table/View 'ACTIVEMQ_ACKS' already exists in Schema 'APP'.
>> SQLState: X0Y32 Vendor code: 20000
>> 18:30:45,484 DEBUG [DefaultJDBCAdapter] Executing SQL: CREATE TABLE
>> ACTIVEMQ_LOCK( ID BIGINT NOT NULL, TIME BIGINT, BROKER_NAME VARCHAR
>> (250), PRIMARY KEY (ID) )
>> 18:30:45,498 DEBUG [DefaultJDBCAdapter] Could not create JDBC tables;
>> The message table already existed. Failure was: CREATE TABLE
>> ACTIVEMQ_LOCK( ID BIGINT NOT NULL, TIME BIGINT, BROKER_NAME VARCHAR
>> (250), PRIMARY KEY (ID) ) Message: Table/View 'ACTIVEMQ_LOCK' already
>> exists in Schema 'APP'. SQLState: X0Y32 Vendor code: 20000
>> 18:30:45,500 DEBUG [DefaultJDBCAdapter] Executing SQL: INSERT INTO
>> ACTIVEMQ_LOCK(ID) VALUES (1)
>> 18:30:45,579 DEBUG [DefaultJDBCAdapter] Could not create JDBC tables;
>> The message table already existed. Failure was: INSERT INTO
>> ACTIVEMQ_LOCK(ID) VALUES (1) Message: The statement was aborted
>> because it would have caused a duplicate key value in a unique or
>> primary key constraint or unique index identified by
>> 'SQL070228030019290' defined on 'ACTIVEMQ_LOCK'. SQLState: 23505
>> Vendor code: 20000
>> 18:30:45,599 INFO  [DefaultDatabaseLocker] Attempting to acquire the
>> exclusive lock to become the Master broker
>> 18:30:45,601 INFO  [DefaultDatabaseLocker] Becoming the master on
>> dataSource: org.apache.derby.jdbc.EmbeddedDataSource@939e84
>> 18:30:45,601 DEBUG [JDBCPersistenceAdapter] Cleaning up old messages.
>> 18:30:45,602 DEBUG [DefaultJDBCAdapter] Executing SQL: DELETE FROM
>> ACTIVEMQ_MSGS WHERE ( EXPIRATION<>0 AND EXPIRATION<?) OR ID <=
>> ( SELECT min(ACTIVEMQ_ACKS.LAST_ACKED_ID) FROM ACTIVEMQ_ACKS WHERE
>> ACTIVEMQ_ACKS.CONTAINER=ACTIVEMQ_MSGS.CONTAINER)
>> 18:30:45,678 DEBUG [DefaultJDBCAdapter] Deleted 0 old message(s).
>> 18:30:45,678 DEBUG [JDBCPersistenceAdapter] Cleanup done.
>> 18:30:45,679 INFO  [JournalPersistenceAdapter] Journal Recovery
>> Started from: Active Journal: using 2 x 20.0 Megs at: /Users/dain/
>> work/openejb/trunk/openejb3/container/openejb-core/activemq-data/
>> localhost/journal
>> 18:30:45,740 INFO  [JournalPersistenceAdapter] Journal Recovered: 1
>> message(s) in transactions recovered.
>> 18:30:45,799 DEBUG [ManagementContext] Failed to create local  
>> registry
>> java.lang.ClassNotFoundException: mx4j.tools.naming.NamingService
>>      at java.net.URLClassLoader$1.run(URLClassLoader.java:200)
>>      at java.security.AccessController.doPrivileged(Native Method)
>>      at java.net.URLClassLoader.findClass(URLClassLoader.java:188)
>>      at java.lang.ClassLoader.loadClass(ClassLoader.java:306)
>>      at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:268)
>>      at java.lang.ClassLoader.loadClass(ClassLoader.java:251)
>>      at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:319)
>>      at java.lang.Class.forName0(Native Method)
>>      at java.lang.Class.forName(Class.java:164)
>>      at
>> org.apache.activemq.broker.jmx.ManagementContext.createConnector
>> (ManagementContext.java:386)
>>      at
>> org.apache.activemq.broker.jmx.ManagementContext.createMBeanServer
>> (ManagementContext.java:367)
>>      at
>> org.apache.activemq.broker.jmx.ManagementContext.findMBeanServer
>> (ManagementContext.java:297)
>>      at
>> org.apache.activemq.broker.jmx.ManagementContext.getMBeanServer
>> (ManagementContext.java:154)
>>      at org.apache.activemq.broker.BrokerService.createRegionBroker
>> (BrokerService.java:1265)
>>      at org.apache.activemq.broker.BrokerService.createBroker
>> (BrokerService.java:1209)
>>      at org.apache.activemq.broker.BrokerService.getBroker
>> (BrokerService.java:508)
>>      at org.apache.activemq.broker.BrokerService.addConnector
>> (BrokerService.java:163)
>>      at org.apache.activemq.broker.DefaultBrokerFactory.createBroker
>> (DefaultBrokerFactory.java:55)
>>      at org.apache.activemq.broker.BrokerFactory.createBroker
>> (BrokerFactory.java:57)
>>      at org.apache.activemq.ra.ActiveMQResourceAdapter.start
>> (ActiveMQResourceAdapter.java:80)
>>      at org.apache.openejb.assembler.classic.Assembler.createResource
>> (Assembler.java:735)
>>      at
>> org.apache.openejb.assembler.classic.Assembler.buildContainerSystem
>> (Assembler.java:279)
>>      at org.apache.openejb.assembler.classic.Assembler.build
>> (Assembler.java:198)
>>      at org.apache.openejb.OpenEJB$Instance.<init>(OpenEJB.java:147)
>>      at org.apache.openejb.OpenEJB.init(OpenEJB.java:280)
>>      at org.apache.openejb.OpenEJB.init(OpenEJB.java:265)
>>      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>      at sun.reflect.NativeMethodAccessorImpl.invoke
>> (NativeMethodAccessorImpl.java:39)
>>      at sun.reflect.DelegatingMethodAccessorImpl.invoke
>> (DelegatingMethodAccessorImpl.java:25)
>>      at java.lang.reflect.Method.invoke(Method.java:585)
>>      at org.apache.openejb.loader.OpenEJBInstance.init
>> (OpenEJBInstance.java:36)
>>      at org.apache.openejb.client.LocalInitialContextFactory.init
>> (LocalInitialContextFactory.java:56)
>>      at
>> org.apache.openejb.client.LocalInitialContextFactory.getInitialContex 
>> t
>> (LocalInitialContextFactory.java:42)
>>      at javax.naming.spi.NamingManager.getInitialContext
>> (NamingManager.java:667)
>>      at javax.naming.InitialContext.getDefaultInitCtx
>> (InitialContext.java:247)
>>      at javax.naming.InitialContext.init(InitialContext.java:223)
>>      at javax.naming.InitialContext.<init>(InitialContext.java:197)
>>      at org.apache.openejb.test.HsqldbTestDatabase.start
>> (HsqldbTestDatabase.java:174)
>>      at org.apache.openejb.test.TestManager.start(TestManager.java: 
>> 79)
>>      at org.apache.openejb.iTest.setUp(iTest.java:57)
>>      at org.apache.openejb.test.TestSuite.run(TestSuite.java:41)
>>      at junit.textui.TestRunner.doRun(TestRunner.java:115)
>>      at com.intellij.rt.execution.junit.IdeaTestRunner.doRun
>> (IdeaTestRunner.java:69)
>>      at junit.textui.TestRunner.doRun(TestRunner.java:108)
>>      at
>> com.intellij.rt.execution.junit.IdeaTestRunner.startRunnerWithArgs
>> (IdeaTestRunner.java:24)
>>      at
>> com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart
>> (JUnitStarter.java:118)
>>      at com.intellij.rt.execution.junit.JUnitStarter.main
>> (JUnitStarter.java:40)
>> 18:30:45,826 DEBUG [ManagementContext] Failed to create local  
>> registry
>> java.rmi.server.ExportException: internal error: ObjID already in use
>>      at sun.rmi.transport.ObjectTable.putTarget(ObjectTable.java:169)
>>      at sun.rmi.transport.Transport.exportObject(Transport.java:75)
>>      at sun.rmi.transport.tcp.TCPTransport.exportObject
>> (TCPTransport.java:196)
>>      at sun.rmi.transport.tcp.TCPEndpoint.exportObject
>> (TCPEndpoint.java:382)
>>      at sun.rmi.transport.LiveRef.exportObject(LiveRef.java:116)
>>      at sun.rmi.server.UnicastServerRef.exportObject
>> (UnicastServerRef.java:180)
>>      at sun.rmi.registry.RegistryImpl.setup(RegistryImpl.java:92)
>>      at sun.rmi.registry.RegistryImpl.<init>(RegistryImpl.java:78)
>>      at java.rmi.registry.LocateRegistry.createRegistry
>> (LocateRegistry.java:186)
>>      at
>> org.apache.activemq.broker.jmx.ManagementContext.createConnector
>> (ManagementContext.java:382)
>>      at
>> org.apache.activemq.broker.jmx.ManagementContext.findMBeanServer
>> (ManagementContext.java:301)
>>      at
>> org.apache.activemq.broker.jmx.ManagementContext.getMBeanServer
>> (ManagementContext.java:154)
>>      at org.apache.activemq.broker.BrokerService.createRegionBroker
>> (BrokerService.java:1265)
>>      at org.apache.activemq.broker.BrokerService.createBroker
>> (BrokerService.java:1209)
>>      at org.apache.activemq.broker.BrokerService.getBroker
>> (BrokerService.java:508)
>>      at org.apache.activemq.broker.BrokerService.addConnector
>> (BrokerService.java:163)
>>      at org.apache.activemq.broker.DefaultBrokerFactory.createBroker
>> (DefaultBrokerFactory.java:55)
>>      at org.apache.activemq.broker.BrokerFactory.createBroker
>> (BrokerFactory.java:57)
>>      at org.apache.activemq.ra.ActiveMQResourceAdapter.start
>> (ActiveMQResourceAdapter.java:80)
>>      at org.apache.openejb.assembler.classic.Assembler.createResource
>> (Assembler.java:735)
>>      at
>> org.apache.openejb.assembler.classic.Assembler.buildContainerSystem
>> (Assembler.java:279)
>>      at org.apache.openejb.assembler.classic.Assembler.build
>> (Assembler.java:198)
>>      at org.apache.openejb.OpenEJB$Instance.<init>(OpenEJB.java:147)
>>      at org.apache.openejb.OpenEJB.init(OpenEJB.java:280)
>>      at org.apache.openejb.OpenEJB.init(OpenEJB.java:265)
>>      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>      at sun.reflect.NativeMethodAccessorImpl.invoke
>> (NativeMethodAccessorImpl.java:39)
>>      at sun.reflect.DelegatingMethodAccessorImpl.invoke
>> (DelegatingMethodAccessorImpl.java:25)
>>      at java.lang.reflect.Method.invoke(Method.java:585)
>>      at org.apache.openejb.loader.OpenEJBInstance.init
>> (OpenEJBInstance.java:36)
>>      at org.apache.openejb.client.LocalInitialContextFactory.init
>> (LocalInitialContextFactory.java:56)
>>      at
>> org.apache.openejb.client.LocalInitialContextFactory.getInitialContex 
>> t
>> (LocalInitialContextFactory.java:42)
>>      at javax.naming.spi.NamingManager.getInitialContext
>> (NamingManager.java:667)
>>      at javax.naming.InitialContext.getDefaultInitCtx
>> (InitialContext.java:247)
>>      at javax.naming.InitialContext.init(InitialContext.java:223)
>>      at javax.naming.InitialContext.<init>(InitialContext.java:197)
>>      at org.apache.openejb.test.HsqldbTestDatabase.start
>> (HsqldbTestDatabase.java:174)
>>      at org.apache.openejb.test.TestManager.start(TestManager.java: 
>> 79)
>>      at org.apache.openejb.iTest.setUp(iTest.java:57)
>>      at org.apache.openejb.test.TestSuite.run(TestSuite.java:41)
>>      at junit.textui.TestRunner.doRun(TestRunner.java:115)
>>      at com.intellij.rt.execution.junit.IdeaTestRunner.doRun
>> (IdeaTestRunner.java:69)
>>      at junit.textui.TestRunner.doRun(TestRunner.java:108)
>>      at
>> com.intellij.rt.execution.junit.IdeaTestRunner.startRunnerWithArgs
>> (IdeaTestRunner.java:24)
>>      at
>> com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart
>> (JUnitStarter.java:118)
>>      at com.intellij.rt.execution.junit.JUnitStarter.main
>> (JUnitStarter.java:40)
>> 18:30:45,955 INFO  [TransportServerThreadSupport] Listening for
>> connections at: tcp://Dains-Computer.local:61616
>> 18:30:45,964 INFO  [TransportConnector] Connector tcp://Dains-
>> Computer.local:61616 Started
>> 18:30:45,968 INFO  [BrokerService] ActiveMQ JMS Message Broker
>> (localhost, ID:Dains-Computer.local-52349-1172889043957-1:0) started
>> 18:30:46,013 INFO  [ManagementContext] JMX consoles can connect to
>> service:jmx:rmi:///jndi/rmi://localhost:1099/jmxrmi
>> INFO - Assembling app: /Users/dain/work/openejb/trunk/openejb3/ 
>> itests/
>> openejb-itests-beans/target/classes
>> ERROR - ActivationSpec destination=request
>> ERROR - ActivationSpec destinationType=javax.jms.Queue
>> 18:30:48,525 DEBUG [ActiveMQEndpointWorker] Starting
>> 18:30:48,539 DEBUG [ActiveMQEndpointWorker] Started
>> 18:30:48,579 DEBUG [WireFormatNegotiator] Sending: WireFormatInfo
>> { version=2, properties={TightEncodingEnabled=true, CacheSize=1024,
>> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
>> StackTraceEnabled=true, MaxInactivityDuration=30000,
>> CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>> 18:30:48,587 DEBUG [TcpTransport] TCP consumer thread starting
>> 18:30:48,593 DEBUG [WireFormatNegotiator] Sending: WireFormatInfo
>> { version=2, properties={TightEncodingEnabled=true, CacheSize=1024,
>> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
>> StackTraceEnabled=true, MaxInactivityDuration=30000,
>> CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>> 18:30:48,593 DEBUG [TcpTransport] TCP consumer thread starting
>> 18:30:48,598 DEBUG [WireFormatNegotiator] Received WireFormat:
>> WireFormatInfo { version=2, properties={TightEncodingEnabled=true,
>> CacheSize=1024, TcpNoDelayEnabled=true, SizePrefixDisabled=false,
>> StackTraceEnabled=true, MaxInactivityDuration=30000,
>> CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>> 18:30:48,607 DEBUG [WireFormatNegotiator] tcp:///127.0.0.1:52354
>> before negotiation: OpenWireFormat{version=2, cacheEnabled=false,
>> stackTraceEnabled=false, tightEncodingEnabled=false,
>> sizePrefixDisabled=false}
>> 18:30:48,608 DEBUG [WireFormatNegotiator] tcp:///127.0.0.1:52354
>> after negotiation: OpenWireFormat{version=2, cacheEnabled=true,
>> stackTraceEnabled=true, tightEncodingEnabled=true,
>> sizePrefixDisabled=false}
>> 18:30:48,610 DEBUG [WireFormatNegotiator] Received WireFormat:
>> WireFormatInfo { version=2, properties={TightEncodingEnabled=true,
>> CacheSize=1024, TcpNoDelayEnabled=true, SizePrefixDisabled=false,
>> StackTraceEnabled=true, MaxInactivityDuration=30000,
>> CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>> 18:30:48,617 DEBUG [WireFormatNegotiator] tcp://localhost/
>> 127.0.0.1:61616 before negotiation: OpenWireFormat{version=2,
>> cacheEnabled=false, stackTraceEnabled=false,
>> tightEncodingEnabled=false, sizePrefixDisabled=false}
>> 18:30:48,623 DEBUG [WireFormatNegotiator] tcp://localhost/
>> 127.0.0.1:61616 after negotiation: OpenWireFormat{version=2,
>> cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true,
>> sizePrefixDisabled=false}
>> 18:30:48,628 DEBUG [TransportConnection] Setting up new connection:
>> org.apache.activemq.broker.jmx.ManagedTransportConnection@b625be
>> 18:30:48,647 DEBUG [AbstractRegion] Adding destination: topic://
>> ActiveMQ.Advisory.Connection
>> 18:30:48,670 DEBUG [AbstractRegion] Adding destination: topic://
>> ActiveMQ.Advisory.Topic
>> 18:30:48,677 DEBUG [AbstractRegion] Adding consumer: ID:Dains-
>> Computer.local-52349-1172889043957-3:0:-1:1
>> 18:30:48,709 DEBUG [AbstractRegion] Adding consumer: ID:Dains-
>> Computer.local-52349-1172889043957-3:0:-1:2
>> 18:30:48,709 DEBUG [AbstractRegion] Adding destination: queue:// 
>> request
>> 18:30:48,721 DEBUG [JournalPersistenceAdapter] Checkpoint started.
>> 18:30:48,720 DEBUG [JournalPersistenceAdapter] Waking for checkpoint
>> to complete.
>> 18:30:48,728 DEBUG [JournalPersistenceAdapter] Checkpoint done.
>> 18:30:48,753 DEBUG [AbstractRegion] Adding destination: topic://
>> ActiveMQ.Advisory.Queue
>> 18:30:48,761 DEBUG [AbstractRegion] Adding destination: topic://
>> ActiveMQ.Advisory.Consumer.Queue.request
>> INFO - OpenEJB ready.
>> OpenEJB ready.
>> 18:30:48,978 DEBUG [TcpTransport] TCP consumer thread starting
>> 18:30:48,980 DEBUG [WireFormatNegotiator] Sending: WireFormatInfo
>> { version=2, properties={TightEncodingEnabled=true, CacheSize=1024,
>> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
>> StackTraceEnabled=true, MaxInactivityDuration=30000,
>> CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>> 18:30:48,980 DEBUG [WireFormatNegotiator] Sending: WireFormatInfo
>> { version=2, properties={TightEncodingEnabled=true, CacheSize=1024,
>> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
>> StackTraceEnabled=true, MaxInactivityDuration=30000,
>> CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>> 18:30:48,981 DEBUG [WireFormatNegotiator] Received WireFormat:
>> WireFormatInfo { version=2, properties={TightEncodingEnabled=true,
>> CacheSize=1024, TcpNoDelayEnabled=true, SizePrefixDisabled=false,
>> StackTraceEnabled=true, MaxInactivityDuration=30000,
>> CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>> 18:30:48,979 DEBUG [TcpTransport] TCP consumer thread starting
>> 18:30:48,984 DEBUG [WireFormatNegotiator] tcp://localhost/
>> 127.0.0.1:61616 before negotiation: OpenWireFormat{version=2,
>> cacheEnabled=false, stackTraceEnabled=false,
>> tightEncodingEnabled=false, sizePrefixDisabled=false}
>> 18:30:48,984 DEBUG [WireFormatNegotiator] Received WireFormat:
>> WireFormatInfo { version=2, properties={TightEncodingEnabled=true,
>> CacheSize=1024, TcpNoDelayEnabled=true, SizePrefixDisabled=false,
>> StackTraceEnabled=true, MaxInactivityDuration=30000,
>> CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>> 18:30:48,986 DEBUG [WireFormatNegotiator] tcp:///127.0.0.1:52355
>> before negotiation: OpenWireFormat{version=2, cacheEnabled=false,
>> stackTraceEnabled=false, tightEncodingEnabled=false,
>> sizePrefixDisabled=false}
>> 18:30:48,987 DEBUG [WireFormatNegotiator] tcp:///127.0.0.1:52355
>> after negotiation: OpenWireFormat{version=2, cacheEnabled=true,
>> stackTraceEnabled=true, tightEncodingEnabled=true,
>> sizePrefixDisabled=false}
>> 18:30:48,987 DEBUG [WireFormatNegotiator] tcp://localhost/
>> 127.0.0.1:61616 after negotiation: OpenWireFormat{version=2,
>> cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true,
>> sizePrefixDisabled=false}
>> 18:30:48,989 DEBUG [TransportConnection] Setting up new connection:
>> org.apache.activemq.broker.jmx.ManagedTransportConnection@ac69b5
>> 18:30:48,991 DEBUG [AbstractRegion] Adding consumer: ID:Dains-
>> Computer.local-52349-1172889043957-3:1:-1:1
>> 18:30:49,013 DEBUG [AbstractRegion] Adding destination: topic://
>> ActiveMQ.Advisory.Producer.Queue.BasicMdbObject
>> 18:30:49,024 DEBUG [TcpTransport] TCP consumer thread starting
>> 18:30:49,024 DEBUG [WireFormatNegotiator] Sending: WireFormatInfo
>> { version=2, properties={TightEncodingEnabled=true, CacheSize=1024,
>> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
>> StackTraceEnabled=true, MaxInactivityDuration=30000,
>> CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>> 18:30:49,024 DEBUG [WireFormatNegotiator] Sending: WireFormatInfo
>> { version=2, properties={TightEncodingEnabled=true, CacheSize=1024,
>> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
>> StackTraceEnabled=true, MaxInactivityDuration=30000,
>> CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>> 18:30:49,024 DEBUG [TcpTransport] TCP consumer thread starting
>> 18:30:49,027 DEBUG [WireFormatNegotiator] Received WireFormat:
>> WireFormatInfo { version=2, properties={TightEncodingEnabled=true,
>> CacheSize=1024, TcpNoDelayEnabled=true, SizePrefixDisabled=false,
>> StackTraceEnabled=true, MaxInactivityDuration=30000,
>> CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>> 18:30:49,028 DEBUG [WireFormatNegotiator] Received WireFormat:
>> WireFormatInfo { version=2, properties={TightEncodingEnabled=true,
>> CacheSize=1024, TcpNoDelayEnabled=true, SizePrefixDisabled=false,
>> StackTraceEnabled=true, MaxInactivityDuration=30000,
>> CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>> 18:30:49,030 DEBUG [WireFormatNegotiator] tcp://localhost/
>> 127.0.0.1:61616 before negotiation: OpenWireFormat{version=2,
>> cacheEnabled=false, stackTraceEnabled=false,
>> tightEncodingEnabled=false, sizePrefixDisabled=false}
>> 18:30:49,031 DEBUG [WireFormatNegotiator] tcp:///127.0.0.1:52356
>> before negotiation: OpenWireFormat{version=2, cacheEnabled=false,
>> stackTraceEnabled=false, tightEncodingEnabled=false,
>> sizePrefixDisabled=false}
>> 18:30:49,033 DEBUG [WireFormatNegotiator] tcp:///127.0.0.1:52356
>> after negotiation: OpenWireFormat{version=2, cacheEnabled=true,
>> stackTraceEnabled=true, tightEncodingEnabled=true,
>> sizePrefixDisabled=false}
>> 18:30:49,032 DEBUG [WireFormatNegotiator] tcp://localhost/
>> 127.0.0.1:61616 after negotiation: OpenWireFormat{version=2,
>> cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true,
>> sizePrefixDisabled=false}
>> 18:30:49,035 DEBUG [TransportConnection] Setting up new connection:
>> org.apache.activemq.broker.jmx.ManagedTransportConnection@253813
>> 18:30:49,037 DEBUG [AbstractRegion] Adding consumer: ID:Dains-
>> Computer.local-52349-1172889043957-3:2:-1:1
>> 18:30:49,042 DEBUG [AbstractRegion] Adding destination: temp-queue://
>> ID:Dains-Computer.local-52349-1172889043957-3:2:1
>> 18:30:49,045 DEBUG [AbstractRegion] Adding destination: topic://
>> ActiveMQ.Advisory.TempQueue
>> 18:30:49,053 DEBUG [AbstractRegion] Adding destination: topic://
>> ActiveMQ.Advisory.Producer.Queue.request
>> 18:30:49,056 DEBUG [ActiveMQSession] Sending message:
>> ActiveMQObjectMessage {commandId = 0, responseRequired = false,
>> messageId = ID:Dains-Computer.local-52349-1172889043957-3:2:1:1:1,
>> originalDestination = null, originalTransactionId = null, producerId
>> = ID:Dains-Computer.local-52349-1172889043957-3:2:1:1, destination =
>> queue://request, transactionId = null, expiration = 0, timestamp =
>> 1172889049053, arrival = 0, correlationId = null, replyTo = temp-
>> queue://ID:Dains-Computer.local-52349-1172889043957-3:2:1, persistent
>> = true, type = null, priority = 4, groupID = null, groupSequence = 0,
>> targetConsumerId = null, compressed = false, userID = null, content =
>> org.apache.activemq.util.ByteSequence@c48b6d, marshalledProperties =
>> null, dataStructure = null, redeliveryCounter = 0, size = 0,
>> properties = null, readOnlyProperties = true, readOnlyBody = true,
>> droppable = false}
>> 18:30:49,061 DEBUG [JournalMessageStore] Journalled message add for:
>> ID:Dains-Computer.local-52349-1172889043957-3:2:1:1:1, at: 0:44555
>> 18:30:49,065 DEBUG [ServerSessionPoolImpl] ServerSession requested.
>>
>> ***************************************
>> Sent request message: ActiveMQObjectMessage {commandId = 0,
>> responseRequired = false, messageId = ID:Dains-
>> Computer.local-52349-1172889043957-3:2:1:1:1, originalDestination =
>> null, originalTransactionId = null, producerId = null, destination =
>> queue://request, transactionId = null, expiration = 0, timestamp =
>> 1172889049053, arrival = 0, correlationId = null, replyTo = temp-
>> queue://ID:Dains-Computer.local-52349-1172889043957-3:2:1, persistent
>> = true, type = null, priority = 4, groupID = null, groupSequence = 0,
>> targetConsumerId = null, compressed = false, userID = null, content =
>> org.apache.activemq.util.ByteSequence@c48b6d, marshalledProperties =
>> null, dataStructure = null, redeliveryCounter = 0, size = 0,
>> properties = null, readOnlyProperties = false, readOnlyBody = false,
>> droppable = false}
>>              to queue: queue://request
>> ***************************************
>>
>>
>>
>> ***************************************
>> Endpoint created
>> ***************************************
>>
>>
>> 18:30:49,079 DEBUG [AbstractRegion] Adding consumer: ID:Dains-
>> Computer.local-52349-1172889043957-3:2:1:1
>> 18:30:49,085 DEBUG [AbstractRegion] Adding destination: topic://
>> ActiveMQ.Advisory.Consumer.Queue.ID:Dains-
>> Computer.local-52349-1172889043957-3:2:1
>>
>> ***************************************
>> Listening for response at : temp-queue://ID:Dains-
>> Computer.local-52349-1172889043957-3:2:1
>> ***************************************
>>
>>
>> 18:30:49,100 DEBUG [ServerSessionPoolImpl] Created a new session:
>> ServerSessionImpl:0
>> 18:30:49,101 DEBUG [ServerSessionImpl:0] Starting run.
>> 18:30:49,103 DEBUG [ServerSessionImpl:0] Work accepted:
>> javax.resource.spi.work.WorkEvent
>> [source=org.apache.geronimo.connector.work.GeronimoWorkManager@8144f7 
>> ]
>> 18:30:49,104 DEBUG [ServerSessionImpl:0] Work started:
>> javax.resource.spi.work.WorkEvent[source=Work :ServerSessionImpl:0]
>> 18:30:49,104 DEBUG [ServerSessionImpl:0] Running
>> 18:30:49,105 DEBUG [ServerSessionImpl:0] run loop start
>>
>> ***************************************
>> Endpoint invoked public abstract void
>> javax.resource.spi.endpoint.MessageEndpoint.beforeDelivery
>> (java.lang.reflect.Method) throws
>> java.lang.NoSuchMethodException,javax.resource.ResourceException
>> ***************************************
>>
>>
>> 18:30:49,116 DEBUG [TransactionContext] Start:
>> [globalId=1000000047544d494400000000000000000000000000000000000000000 
>> 000
>> 0000000,branchId=1000000047544d49440000000000000000000000000000000000 
>> 000
>> 00000000000000]
>> 18:30:49,123 DEBUG [TransactionContext] Started XA transaction: XID:
>> 1197822575:010000000000000047544d494400000000000000000000000000000000 
>> 000
>> 0000000000000000000000000000000000000000000000000000000000000000000:0 
>> 100
>> 00000000000047544d494400000000000000000000000000000000000000000000000 
>> 000
>> 0000000000000000000000000000000000000000000000000000
>>
>> ***************************************
>> Endpoint invoked public abstract void
>> javax.jms.MessageListener.onMessage(javax.jms.Message)
>> ***************************************
>>
>>
>>
>> ***************************************
>> Got message: ActiveMQObjectMessage {commandId = 6, responseRequired =
>> true, messageId = ID:Dains-
>> Computer.local-52349-1172889043957-3:2:1:1:1, originalDestination =
>> null, originalTransactionId = null, producerId = ID:Dains-
>> Computer.local-52349-1172889043957-3:2:1:1, destination = queue://
>> request, transactionId = null, expiration = 0, timestamp =
>> 1172889049060, arrival = 0, correlationId = null, replyTo = temp-
>> queue://ID:Dains-Computer.local-52349-1172889043957-3:2:1, persistent
>> = true, type = null, priority = 4, groupID = null, groupSequence = 0,
>> targetConsumerId = null, compressed = false, userID = null, content =
>> org.apache.activemq.util.ByteSequence@3fde4, marshalledProperties =
>> null, dataStructure = null, redeliveryCounter = 0, size = 0,
>> properties = null, readOnlyProperties = true, readOnlyBody = true,
>> droppable = false}
>> ***************************************
>>
>>
>> 18:30:49,132 DEBUG [WireFormatNegotiator] Sending: WireFormatInfo
>> { version=2, properties={TightEncodingEnabled=true, CacheSize=1024,
>> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
>> StackTraceEnabled=true, MaxInactivityDuration=30000,
>> CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>> 18:30:49,132 DEBUG [TcpTransport] TCP consumer thread starting
>> 18:30:49,132 DEBUG [TcpTransport] TCP consumer thread starting
>> 18:30:49,132 DEBUG [WireFormatNegotiator] Sending: WireFormatInfo
>> { version=2, properties={TightEncodingEnabled=true, CacheSize=1024,
>> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
>> StackTraceEnabled=true, MaxInactivityDuration=30000,
>> CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>> 18:30:49,134 DEBUG [WireFormatNegotiator] Received WireFormat:
>> WireFormatInfo { version=2, properties={TightEncodingEnabled=true,
>> CacheSize=1024, TcpNoDelayEnabled=true, SizePrefixDisabled=false,
>> StackTraceEnabled=true, MaxInactivityDuration=30000,
>> CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>> 18:30:49,137 DEBUG [WireFormatNegotiator] tcp:///127.0.0.1:52357
>> before negotiation: OpenWireFormat{version=2, cacheEnabled=false,
>> stackTraceEnabled=false, tightEncodingEnabled=false,
>> sizePrefixDisabled=false}
>> 18:30:49,138 DEBUG [WireFormatNegotiator] tcp:///127.0.0.1:52357
>> after negotiation: OpenWireFormat{version=2, cacheEnabled=true,
>> stackTraceEnabled=true, tightEncodingEnabled=true,
>> sizePrefixDisabled=false}
>> 18:30:49,137 DEBUG [WireFormatNegotiator] Received WireFormat:
>> WireFormatInfo { version=2, properties={TightEncodingEnabled=true,
>> CacheSize=1024, TcpNoDelayEnabled=true, SizePrefixDisabled=false,
>> StackTraceEnabled=true, MaxInactivityDuration=30000,
>> CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>> 18:30:49,140 DEBUG [WireFormatNegotiator] tcp://localhost/
>> 127.0.0.1:61616 before negotiation: OpenWireFormat{version=2,
>> cacheEnabled=false, stackTraceEnabled=false,
>> tightEncodingEnabled=false, sizePrefixDisabled=false}
>> 18:30:49,141 DEBUG [WireFormatNegotiator] tcp://localhost/
>> 127.0.0.1:61616 after negotiation: OpenWireFormat{version=2,
>> cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true,
>> sizePrefixDisabled=false}
>> 18:30:49,142 DEBUG [TransportConnection] Setting up new connection:
>> org.apache.activemq.broker.jmx.ManagedTransportConnection@d205d2
>> 18:30:49,144 DEBUG [AbstractRegion] Adding consumer: ID:Dains-
>> Computer.local-52349-1172889043957-3:3:-1:1
>> 18:30:49,147 DEBUG [AbstractRegion] Adding destination: topic://
>> ActiveMQ.Advisory.Producer.Queue.ID:Dains-
>> Computer.local-52349-1172889043957-3:2:1
>> 18:30:49,147 DEBUG [ActiveMQSession] Sending message:
>> ActiveMQObjectMessage {commandId = 0, responseRequired = false,
>> messageId = ID:Dains-Computer.local-52349-1172889043957-3:3:1:1:1,
>> originalDestination = null, originalTransactionId = null, producerId
>> = ID:Dains-Computer.local-52349-1172889043957-3:3:1:1, destination =
>> temp-queue://ID:Dains-Computer.local-52349-1172889043957-3:2:1,
>> transactionId = null, expiration = 0, timestamp = 1172889049147,
>> arrival = 0, correlationId = null, replyTo = null, persistent = true,
>> type = null, priority = 4, groupID = null, groupSequence = 0,
>> targetConsumerId = null, compressed = false, userID = null, content =
>> org.apache.activemq.util.ByteSequence@ad49d8, marshalledProperties =
>> null, dataStructure = null, redeliveryCounter = 0, size = 0,
>> properties = null, readOnlyProperties = true, readOnlyBody = true,
>> droppable = false}
>>
>> ***************************************
>> Sent response message: ActiveMQObjectMessage {commandId = 0,
>> responseRequired = false, messageId = ID:Dains-
>> Computer.local-52349-1172889043957-3:3:1:1:1, originalDestination =
>> null, originalTransactionId = null, producerId = null, destination =
>> temp-queue://ID:Dains-Computer.local-52349-1172889043957-3:2:1,
>> transactionId = null, expiration = 0, timestamp = 1172889049147,
>> arrival = 0, correlationId = null, replyTo = null, persistent = true,
>> type = null, priority = 4, groupID = null, groupSequence = 0,
>> targetConsumerId = null, compressed = false, userID = null, content =
>> org.apache.activemq.util.ByteSequence@ad49d8, marshalledProperties =
>> null, dataStructure = null, redeliveryCounter = 0, size = 0,
>> properties = null, readOnlyProperties = false, readOnlyBody = false,
>> droppable = false}
>>               to queue: temp-queue://ID:Dains-
>> Computer.local-52349-1172889043957-3:2:1
>> ***************************************
>>
>>
>> 18:30:49,158 DEBUG [AbstractRegion] Removing consumer: ID:Dains-
>> Computer.local-52349-1172889043957-3:3:-1:1
>> 18:30:49,160 DEBUG [TransportConnection] Stopping connection: /
>> 127.0.0.1:52357
>> 18:30:49,161 DEBUG [TransportConnection] Stopped connection: /
>> 127.0.0.1:52357
>>
>> ***************************************
>> Endpoint invoked public abstract void
>> javax.resource.spi.endpoint.MessageEndpoint.afterDelivery() throws
>> javax.resource.ResourceException
>> ***************************************
>>
>>
>> 18:30:49,163 DEBUG [JournalMessageStore] Journalled transacted
>> message remove for: ID:Dains-
>> Computer.local-52349-1172889043957-3:2:1:1:1, at: 0:45015
>> 18:30:49,165 DEBUG [TransactionContext] End:
>> [globalId=1000000047544d494400000000000000000000000000000000000000000 
>> 000
>> 0000000,branchId=1000000047544d49440000000000000000000000000000000000 
>> 000
>> 00000000000000]
>> 18:30:49,167 DEBUG [TransactionContext] Ended XA transaction: XID:
>> 1197822575:010000000000000047544d494400000000000000000000000000000000 
>> 000
>> 0000000000000000000000000000000000000000000000000000000000000000000:0 
>> 100
>> 00000000000047544d494400000000000000000000000000000000000000000000000 
>> 000
>> 0000000000000000000000000000000000000000000000000000
>> 18:30:49,169 DEBUG [TransactionContext] Commit:
>> [globalId=1000000047544d494400000000000000000000000000000000000000000 
>> 000
>> 0000000,branchId=1000000047544d49440000000000000000000000000000000000 
>> 000
>> 00000000000000]
>> 18:30:49,170 DEBUG [XATransaction] XA Transaction commit: XID:
>> 1197822575:010000000000000047544d494400000000000000000000000000000000 
>> 000
>> 0000000000000000000000000000000000000000000000000000000000000000000:0 
>> 100
>> 00000000000047544d494400000000000000000000000000000000000000000000000 
>> 000
>> 0000000000000000000000000000000000000000000000000000
>> 18:30:49,179 DEBUG [JournalMessageStore] Transacted message remove
>> commit for: ID:Dains-Computer.local-52349-1172889043957-3:2:1:1:1,
>> at: 0:45015
>> 18:30:49,182 DEBUG [ServerSessionImpl:0] run loop end
>> 18:30:49,183 DEBUG [ServerSessionPoolImpl] Session returned to pool:
>> ServerSessionImpl:0
>> 18:30:49,185 DEBUG [ServerSessionImpl:0] Run finished
>> 18:30:49,187 DEBUG [ServerSessionImpl:0] Work completed:
>> javax.resource.spi.work.WorkEvent[source=Work :ServerSessionImpl:0]
>> 18:30:59,095 DEBUG [AbstractRegion] Removing consumer: ID:Dains-
>> Computer.local-52349-1172889043957-3:2:1:1
>> 18:30:59,099 DEBUG [AbstractRegion] Removing consumer: ID:Dains-
>> Computer.local-52349-1172889043957-3:2:-1:1
>> 18:30:59,100 DEBUG [AbstractRegion] Removing destination: temp-
>> queue://ID:Dains-Computer.local-52349-1172889043957-3:2:1
>> 18:30:59,102 DEBUG [AbstractRegion] Removing destination: topic://
>> ActiveMQ.Advisory.Consumer.Queue.ID:Dains-
>> Computer.local-52349-1172889043957-3:2:1
>> 18:30:59,103 DEBUG [AbstractRegion] Removing destination: topic://
>> ActiveMQ.Advisory.Producer.Queue.ID:Dains-
>> Computer.local-52349-1172889043957-3:2:1
>> 18:30:59,104 DEBUG [TransportConnection] Stopping connection: /
>> 127.0.0.1:52356
>> 18:30:59,107 DEBUG [TransportConnection] Stopped connection: /
>> 127.0.0.1:52356
>> 18:30:59,247 INFO  [BrokerService] ActiveMQ Message Broker
>> (localhost, ID:Dains-Computer.local-52349-1172889043957-1:0) is
>> shutting down
>> 18:30:59,247 DEBUG [BrokerService] Caught exception, must be shutting
>> down: java.lang.IllegalStateException: Shutdown in progress
>> 18:31:01,140 INFO  [TransportConnector] Connector tcp:/Dains-
>> Computer.local:61616 Stopped
>> 18:31:01,145 DEBUG [JournalPersistenceAdapter] Waking for checkpoint
>> to complete.
>> 18:31:01,145 DEBUG [JournalPersistenceAdapter] Checkpoint started.
>> 18:31:01,148 DEBUG [JournalPersistenceAdapter] Marking journal at:
>> 0:45015
>> 18:31:01,149 DEBUG [JournalPersistenceAdapter] Checkpoint done.
>> 18:31:01,157 INFO  [BrokerService] ActiveMQ JMS Message Broker
>> (localhost, ID:Dains-Computer.local-52349-1172889043957-1:0) stopped
>>
>>
>
>
> -- 
>
> James
> -------
> http://radio.weblogs.com/0112098/


Mime
View raw message