Hello, we have a openejb - tomcat installation using activemq to manage jms
messages.
These are the activemq jars we have installed:
# find . -name "*jar" |grep active
./webapps/openejb/lib/activemq-core-4.1.1.jar
./webapps/openejb/lib/activeio-core-3.0.0-incubator.jar
./webapps/openejb/lib/activemq-ra-4.1.1.jar
And this is the configuration, we are using a oracle db with jounaling (this
is our activemq.xml configuration):
<persistenceAdapter>
<journaledJDBC journalLogFiles="5"
dataDirectory="${catalina.base}/activemq-data" dataSource="#oracle-ds"
useJournal="true" useDatabaseLock="false" createTablesOnStartup="false">
<statements>
<statements tablePrefix="GRM_WORKFLOW_" messageTableName="MSGS"
durableSubAcksTableName="ACKS" lockTableName="LOCK"/>
</statements>
</journaledJDBC>
</persistenceAdapter>
The problem was that in a shutdown and start of the application, the journal
got corrupted. This is the error that appears:
2010-07-01 08:06:21,113 ERROR [main]
"org.apache.activemq.broker.BrokerService": Failed to start ActiveMQ JMS
Message Broker. Reason: java.io.IOException: No record at (0:230016) found.
I suppose it gets corrupted during the shutdown, but I don't know if is due
to a activemq 4.1.1 bug, or an error in openejb management of activemq
shutdown.
This is the log during the shutdown:
2010-07-01 08:06:11,908 DEBUG [VMTransport]
"org.apache.activemq.broker.region.AbstractRegion": Removing consumer:
ID:tuerca-01-38044-1277794971538-3:0:-1:1
2010-07-01 08:06:11,914 DEBUG [VMTransport]
"org.apache.activemq.broker.region.AbstractRegion": Removing consumer:
ID:tuerca-01-38044-1277794971538-3:2:-1:2
2010-07-01 08:06:11,915 DEBUG [VMTransport]
"org.apache.activemq.broker.region.AbstractRegion": Removing consumer:
ID:tuerca-01-38044-1277794971538-3:2:-1:1
2010-07-01 08:06:11,915 DEBUG [VMTransport]
"org.apache.activemq.broker.region.AbstractRegion": Removing consumer:
ID:tuerca-01-38044-1277794971538-3:3:-1:2
2010-07-01 08:06:11,916 DEBUG [VMTransport]
"org.apache.activemq.broker.region.AbstractRegion": Removing consumer:
ID:tuerca-01-38044-1277794971538-3:3:-1:1
2010-07-01 08:06:11,916 DEBUG [VMTransport]
"org.apache.activemq.broker.TransportConnection": Stopping connection:
vm://localhost#6
2010-07-01 08:06:11,917 DEBUG [VMTransport]
"org.apache.activemq.broker.TransportConnection": Stopped connection:
vm://localhost#6
2010-07-01 08:06:11,918 DEBUG [VMTransport]
"org.apache.activemq.broker.region.AbstractRegion": Removing consumer:
ID:tuerca-01-38044-1277794971538-3:1:-1:2
2010-07-01 08:06:11,919 DEBUG [VMTransport]
"org.apache.activemq.broker.region.AbstractRegion": Removing consumer:
ID:tuerca-01-38044-1277794971538-3:1:-1:1
2010-07-01 08:06:11,920 DEBUG [VMTransport]
"org.apache.activemq.broker.TransportConnection": Stopping connection:
vm://localhost#1
2010-07-01 08:06:11,920 DEBUG [VMTransport]
"org.apache.activemq.broker.TransportConnection": Stopped connection:
vm://localhost#1
2010-07-01 08:06:11,933 INFO [main]
"org.apache.activemq.broker.BrokerService": ActiveMQ Message Broker
(localhost, ID:tuerca-01-38044-1277794971538-1:0) is shutting down
2010-07-01 08:06:11,934 DEBUG [main]
"org.apache.activemq.transport.vm.VMTransportFactory": Shutting down VM
connectors for broker: localhost
2010-07-01 08:06:11,934 DEBUG [main]
"org.apache.activemq.broker.TransportConnection": Stopping connection:
vm://localhost#0
2010-07-01 08:06:11,934 DEBUG [main]
"org.apache.activemq.broker.TransportConnection": Stopped connection:
vm://localhost#0
2010-07-01 08:06:11,934 DEBUG [main]
"org.apache.activemq.broker.TransportConnection": Stopping connection:
vm://localhost#3
2010-07-01 08:06:11,934 DEBUG [main]
"org.apache.activemq.broker.TransportConnection": Stopped connection:
vm://localhost#3
2010-07-01 08:06:11,934 DEBUG [main]
"org.apache.activemq.broker.TransportConnection": Stopping connection:
vm://localhost#8
2010-07-01 08:06:11,934 DEBUG [main]
"org.apache.activemq.broker.TransportConnection": Stopped connection:
vm://localhost#8
2010-07-01 08:06:11,934 DEBUG [main]
"org.apache.activemq.broker.TransportConnection": Stopping connection:
vm://localhost#10
2010-07-01 08:06:11,934 DEBUG [main]
"org.apache.activemq.broker.TransportConnection": Stopped connection:
vm://localhost#10
2010-07-01 08:06:11,934 DEBUG [main]
"org.apache.activemq.broker.TransportConnection": Stopping connection:
vm://localhost#12
2010-07-01 08:06:11,937 DEBUG [main]
"org.apache.activemq.broker.TransportConnection": Stopped connection:
vm://localhost#12
2010-07-01 08:06:11,937 INFO [main]
"org.apache.activemq.broker.TransportConnector": Connector vm://localhost
Stopped
2010-07-01 08:06:11,937 DEBUG [main]
"org.apache.activemq.store.journal.JournalPersistenceAdapter": Waking for
checkpoint to complete.
2010-07-01 08:06:11,938 DEBUG [Persistence Adaptor Task]
"org.apache.activemq.store.journal.JournalPersistenceAdapter": Checkpoint
started.
2010-07-01 08:06:12,065 DEBUG [Persistence Adaptor Task]
"org.apache.activemq.store.journal.JournalPersistenceAdapter": Marking
journal at: 0:230016
2010-07-01 08:06:12,094 DEBUG [Persistence Adaptor Task]
"org.apache.activemq.store.journal.JournalPersistenceAdapter": Checkpoint
done.
2010-07-01 08:06:12,128 INFO [main]
"org.apache.activemq.broker.BrokerService": ActiveMQ JMS Message Broker
(localhost, ID:tuerca-01-38044-1277794971538-1:0) stopped
And this is the log during the startup:
2010-07-01 08:06:20,737 INFO [main]
"org.apache.activemq.broker.BrokerService": ActiveMQ 4.1.1 JMS Message
Broker (localhost) is starting
2010-07-01 08:06:20,737 INFO [main]
"org.apache.activemq.broker.BrokerService": For help or more information
please see: http://incubator.apache.org/activemq/
2010-07-01 08:06:21,051 INFO [main]
"org.apache.activemq.store.jdbc.JDBCPersistenceAdapter": Database driver
recognized: [oracle_jdbc_driver]
2010-07-01 08:06:21,051 DEBUG [main]
"org.apache.activemq.store.jdbc.JDBCPersistenceAdapter": Cleaning up old
messages.
2010-07-01 08:06:21,051 DEBUG [main]
"org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter": Executing SQL:
DELETE FROM GRM_WORKFLOW_MSGS WHERE (EXPIRATION != 0 AND EXPIRATION < ?) OR
ID <= ( SELECT min(GRM_WORKFLOW_ACKS.LAST_ACKED_ID) FROM GRM_WORKFLOW_ACKS
WHERE GRM_WORKFLOW_ACKS.CONTAINER = GRM_WORKFLOW_MSGS.CONTAINER)
2010-07-01 08:06:21,102 DEBUG [main]
"org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter": Deleted 0 old
message(s).
2010-07-01 08:06:21,103 DEBUG [main]
"org.apache.activemq.store.jdbc.JDBCPersistenceAdapter": Cleanup done.
2010-07-01 08:06:21,103 INFO [main]
"org.apache.activemq.store.journal.JournalPersistenceAdapter": Journal
Recovery Started from: Active Journal: using 5 x 20.0 Megs at:
/opt/GEREMIAS/instancias-tomcat/GRMMAR.8202/activemq-data/journal
2010-07-01 08:06:21,113 ERROR [main]
"org.apache.activemq.broker.BrokerService": Failed to start ActiveMQ JMS
Message Broker. Reason: java.io.IOException: No record at (0:230016) found.
java.io.IOException: No record at (0:230016) found.
at
org.apache.activeio.journal.active.JournalImpl.handleExecutionException(JournalImpl.java:396)
at
org.apache.activeio.journal.active.JournalImpl.read(JournalImpl.java:424)
at
org.apache.activemq.store.journal.JournalPersistenceAdapter.recover(JournalPersistenceAdapter.java:469)
at
org.apache.activemq.store.journal.JournalPersistenceAdapter.start(JournalPersistenceAdapter.java:225)
at
org.apache.activemq.broker.BrokerService.createRegionBroker(BrokerService.java:1251)
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.start(BrokerService.java:394)
at
org.apache.activemq.xbean.XBeanBrokerService.afterPropertiesSet(XBeanBrokerService.java:47)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1062)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1029)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:420)
at
org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:245)
at
org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:141)
at
org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:242)
at
org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:156)
at
org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:290)
at
org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:348)
at
org.apache.xbean.spring.context.ClassPathXmlApplicationContext.<init>(ClassPathXmlApplicationContext.java:161)
at
org.apache.xbean.spring.context.ClassPathXmlApplicationContext.<init>(ClassPathXmlApplicationContext.java:51)
at
org.apache.activemq.xbean.XBeanBrokerFactory.createBroker(XBeanBrokerFactory.java:41)
at
org.apache.activemq.broker.BrokerFactory.createBroker(BrokerFactory.java:57)
at
org.apache.activemq.ra.ActiveMQResourceAdapter.start(ActiveMQResourceAdapter.java:80)
at
org.apache.openejb.resource.activemq.ActiveMQResourceAdapter.start(ActiveMQResourceAdapter.java:130)
at
org.apache.openejb.assembler.classic.Assembler.createResource(Assembler.java:1107)
at
org.apache.openejb.assembler.classic.Assembler.buildContainerSystem(Assembler.java:354)
at
org.apache.openejb.assembler.classic.Assembler.build(Assembler.java:277)
at org.apache.openejb.OpenEJB$Instance.<init>(OpenEJB.java:150)
at org.apache.openejb.OpenEJB.init(OpenEJB.java:299)
at
org.apache.openejb.tomcat.catalina.TomcatLoader.init(TomcatLoader.java:121)
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.Embedder.init(Embedder.java:75)
at
org.apache.openejb.tomcat.loader.TomcatHook.hook(TomcatHook.java:98)
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.tomcat.loader.TomcatEmbedder.embed(TomcatEmbedder.java:74)
at
org.apache.openejb.tomcat.loader.OpenEJBListener.lifecycleEvent(OpenEJBListener.java:50)
at
org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:120)
at
org.apache.catalina.core.StandardServer.initialize(StandardServer.java:757)
at org.apache.catalina.startup.Catalina.load(Catalina.java:504)
at org.apache.catalina.startup.Catalina.load(Catalina.java:524)
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.catalina.startup.Bootstrap.load(Bootstrap.java:267)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:432)
Caused by: org.apache.activeio.journal.InvalidRecordLocationException: No
record at (0:230016) found.
at
org.apache.activeio.journal.active.LogFileManager.readRecordInfo(LogFileManager.java:373)
at
org.apache.activeio.journal.active.LogFileManager.readPacket(LogFileManager.java:450)
at
org.apache.activeio.journal.active.JournalImpl$5.call(JournalImpl.java:416)
at
edu.emory.mathcs.backport.java.util.concurrent.FutureTask.run(FutureTask.java:176)
at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
2010-07-01 08:06:24,157 INFO [main]
"org.apache.activemq.broker.BrokerService": ActiveMQ 4.1.1 JMS Message
Broker (localhost) is starting
2010-07-01 08:06:24,157 INFO [main]
"org.apache.activemq.broker.BrokerService": For help or more information
please see: http://incubator.apache.org/activemq/
--
View this message in context:
http://old.nabble.com/Journal-Corrupted-in-ActiveMQ-4.1.1-%28shipped-with-OpenEJB-3.1%29-tp29212806p29212806.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
