On Mar 14, 2008, at 6:25 AM, Tomasz Mazan wrote:


Hi Guys
I got very ugly (and blocking) issue with HOWL.
After processing 20k request to my webservice whose are translated to ~120k XA transactions (postgres + jms) Geronimo hangs up and does not respond on requests via HTTP, request to JMS engine (from HermesJMS) and ignores tries
to shutdown server.

I stopped Geronimo with kill -9 and tried to start it again and got
exception:

Module 11/69 org.apache.geronimo.configs/activemq-ra/2.1-SNAPSHOT/car
10:22:15,325 ERROR [GBeanInstanceState] Error while starting; GBean is now
in the FAILED state:
abstractName="org.apache.geronimo.configs/transaction/2.1-SNAPSHOT/ car?ServiceModule=org.apache.geronimo.configs/transaction/2.1- SNAPSHOT/car,j2eeType=TransactionLog,name=HOWLTransactionLog"
java.lang.IllegalArgumentException: Negative position
       at sun.nio.ch.FileChannelImpl.read(FileChannelImpl.java:613)
       at
org.objectweb.howl.log.BlockLogBuffer.read(BlockLogBuffer.java:412)
       at
org.objectweb.howl.log.LogFileManager.read(LogFileManager.java:641)
       at
org.objectweb.howl.log.LogBufferManager.replay(LogBufferManager.java: 869)
       at org.objectweb.howl.log.Logger.replay(Logger.java:396)
       at org.objectweb.howl.log.xa.XALogger.open(XALogger.java:897)
       at
org.apache.geronimo.transaction.log.HOWLLog.doStart(HOWLLog.java:224)
       at
org .apache .geronimo .gbean.runtime.GBeanInstance.createInstance(GBeanInstance.java:996)
       at
org .apache .geronimo .gbean .runtime.GBeanInstanceState.attemptFullStart(GBeanInstanceState.java: 268)
       at
org .apache .geronimo .gbean.runtime.GBeanInstanceState.start(GBeanInstanceState.java:102)
       at
org .apache .geronimo.gbean.runtime.GBeanInstance.start(GBeanInstance.java:539)
       at
org .apache .geronimo .gbean.runtime.GBeanDependency.attemptFullStart(GBeanDependency.java: 111)
       at
org .apache .geronimo .gbean.runtime.GBeanDependency.addTarget(GBeanDependency.java:146)
       at
org.apache.geronimo.gbean.runtime.GBeanDependency $1.running(GBeanDependency.java:120)
       at
org .apache .geronimo .kernel .basic .BasicLifecycleMonitor.fireRunningEvent(BasicLifecycleMonitor.java: 176)
       at
org.apache.geronimo.kernel.basic.BasicLifecycleMonitor.access $300(BasicLifecycleMonitor.java:44)
       at
org.apache.geronimo.kernel.basic.BasicLifecycleMonitor $RawLifecycleBroadcaster.fireRunningEvent(BasicLifecycleMonitor.java: 254)
       at
org .apache .geronimo .gbean .runtime.GBeanInstanceState.attemptFullStart(GBeanInstanceState.java: 294)
       at
org .apache .geronimo .gbean.runtime.GBeanInstanceState.start(GBeanInstanceState.java:102)
       at
org .apache .geronimo .gbean .runtime.GBeanInstanceState.startRecursive(GBeanInstanceState.java: 124)
       at
org .apache .geronimo .gbean.runtime.GBeanInstance.startRecursive(GBeanInstance.java:553)
       at
org .apache .geronimo .kernel.basic.BasicKernel.startRecursiveGBean(BasicKernel.java:379)
       at
org .apache .geronimo .kernel .config .ConfigurationUtil.startConfigurationGBeans(ConfigurationUtil.java: 448)
       at
org .apache .geronimo .kernel .config .KernelConfigurationManager.start(KernelConfigurationManager.java:187)
       at
org .apache .geronimo .kernel .config .SimpleConfigurationManager .startConfiguration(SimpleConfigurationManager.java:534)
       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:597)
       at
org .apache .geronimo .gbean .runtime.ReflectionMethodInvoker.invoke(ReflectionMethodInvoker.java: 34)
       at
org .apache .geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:124)
       at
org .apache .geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:830)
       at
org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java: 57)
       at
org .apache .geronimo .kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
       at
org .apache .geronimo .kernel .basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java: 96)
       at
org.apache.geronimo.gbean.GBeanLifecycle$$EnhancerByCGLIB$ $5ebee84a.startConfiguration(<generated>)
       at
org .apache .geronimo.system.main.EmbeddedDaemon.doStartup(EmbeddedDaemon.java: 156)
       at
org .apache .geronimo.system.main.EmbeddedDaemon.execute(EmbeddedDaemon.java:78)
       at
org .apache .geronimo .kernel .util .MainConfigurationBootstrapper .main(MainConfigurationBootstrapper.java:45)
       at
org.apache.geronimo.cli.AbstractCLI.executeMain(AbstractCLI.java:67)
at org.apache.geronimo.cli.daemon.DaemonCLI.main(DaemonCLI.java:30)
Server Startup failed

org.apache.geronimo.kernel.config.LifecycleException: start of
org.apache.geronimo.configs/activemq-ra/2.1-SNAPSHOT/car failed
       at
org .apache .geronimo .kernel .config .SimpleConfigurationManager .startConfiguration(SimpleConfigurationManager.java:551)
       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:597)
       at
org .apache .geronimo .gbean .runtime.ReflectionMethodInvoker.invoke(ReflectionMethodInvoker.java: 34)
       at
org .apache .geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:124)
       at
org .apache .geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:830)
       at
org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java: 57)
       at
org .apache .geronimo .kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
       at
org .apache .geronimo .kernel .basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java: 96)
       at
org.apache.geronimo.gbean.GBeanLifecycle$$EnhancerByCGLIB$ $5ebee84a.startConfiguration(<generated>)
       at
org .apache .geronimo.system.main.EmbeddedDaemon.doStartup(EmbeddedDaemon.java: 156)
       at
org .apache .geronimo.system.main.EmbeddedDaemon.execute(EmbeddedDaemon.java:78)
       at
org .apache .geronimo .kernel .util .MainConfigurationBootstrapper .main(MainConfigurationBootstrapper.java:45)
       at
org.apache.geronimo.cli.AbstractCLI.executeMain(AbstractCLI.java:67)
at org.apache.geronimo.cli.daemon.DaemonCLI.main(DaemonCLI.java:30) Caused by: org.apache.geronimo.kernel.config.InvalidConfigException: Unknown
start exception
       at
org .apache .geronimo .kernel .config .ConfigurationUtil.startConfigurationGBeans(ConfigurationUtil.java: 514)
       at
org .apache .geronimo .kernel .config .KernelConfigurationManager.start(KernelConfigurationManager.java:187)
       at
org .apache .geronimo .kernel .config .SimpleConfigurationManager .startConfiguration(SimpleConfigurationManager.java:534)
       ... 16 more
Caused by: org.apache.geronimo.gbean.InvalidConfigurationException:
Configuration org.apache.geronimo.configs/transaction/2.1-SNAPSHOT/car
failed to start due to the following reasons:
 The service
ServiceModule=org.apache.geronimo.configs/transaction/2.1-SNAPSHOT/ car,j2eeType=JCAConnectionTracker,name=ConnectionTracker
did not start because
org.apache.geronimo.configs/transaction/2.1-SNAPSHOT/car? ServiceModule=org.apache.geronimo.configs/transaction/2.1-SNAPSHOT/ car,j2eeType=JTAResource,name=TransactionManager
did not start.
 The service
ServiceModule=org.apache.geronimo.configs/transaction/2.1-SNAPSHOT/ car,j2eeType=JCAWorkManager,name=DefaultWorkManager
did not start because
org.apache.geronimo.configs/transaction/2.1-SNAPSHOT/car? ServiceModule=org.apache.geronimo.configs/transaction/2.1-SNAPSHOT/ car,j2eeType=JTAResource,name=TransactionManager
did not start.
 The service
ServiceModule=org.apache.geronimo.configs/transaction/2.1-SNAPSHOT/ car,j2eeType=TransactionLog,name=HOWLTransactionLog
did not start because Negative position
 The service
ServiceModule=org.apache.geronimo.configs/transaction/2.1-SNAPSHOT/ car,j2eeType=JTAResource,name=TransactionManager
did not start because
org.apache.geronimo.configs/transaction/2.1-SNAPSHOT/car? ServiceModule=org.apache.geronimo.configs/transaction/2.1-SNAPSHOT/ car,j2eeType=TransactionLog,name=HOWLTransactionLog
did not start.

       at
org .apache .geronimo .kernel .config .ConfigurationUtil.startConfigurationGBeans(ConfigurationUtil.java: 477)
       ... 18 more

I've found that HOWL's log-file reached 4G !

Hi Beniamin,
The size of the logfile is the reason for the IllegalArgumentException -- seems to be an integer overflow. I think the following bug report describes the situation -- http://forge.objectweb.org/tracker/index.php?func=detail&aid=306425&group_id=92&atid=100092 . HOWL 1.0.2 is supposed to detect the condition, but, IIUC, does not fix the underlying problem. Also, I'm not finding 1.0.2 on a maven repo...

Looks like we have some digging to do around our transaction logging. I'm not familiar with the specifics of the HOWL implementation... I'll see if I can devote some spare cycles to this, but would be great if anyone else could investigate.

The cause of the IllegalStateException is understood and should be fixed in http://issues.apache.org/jira/browse/OPENEJB-702

--kevan



I have to add that each XA transaction with accesing activemq causes log
like below:

10:49:11,398 ERROR [Transaction] Please correct the integration and supply a
NamedXAResource
java.lang.IllegalStateException: Cannot log transactions as
[EMAIL PROTECTED] is not a
NamedXAResource.
       at
org.apache.geronimo.transaction.manager.TransactionImpl $TransactionBranch.getResourceName(TransactionImpl.java:697)
       at
org.apache.geronimo.transaction.log.HOWLLog.prepare(HOWLLog.java:254)
       at
org .apache .geronimo .transaction .manager.TransactionImpl.internalPrepare(TransactionImpl.java:444)
       at
org .apache .geronimo .transaction.manager.TransactionImpl.commit(TransactionImpl.java:316)
       at
org .apache .geronimo .transaction .manager.TransactionManagerImpl.commit(TransactionManagerImpl.java: 245)
       at
org .apache .openejb .core .transaction .TransactionPolicy.commitTransaction(TransactionPolicy.java:140)
       at
org .apache .openejb.core.transaction.TxRequired.afterInvoke(TxRequired.java:75)
       at
org .apache .openejb.core.mdb.MdbContainer.afterDelivery(MdbContainer.java:388)
       at
org .apache .openejb.core.mdb.EndpointHandler.afterDelivery(EndpointHandler.java: 274)
       at
org .apache.openejb.core.mdb.EndpointHandler.invoke(EndpointHandler.java: 164)
       at $Proxy42.afterDelivery(Unknown Source)
       at
org.apache.activemq.ra.MessageEndpointProxy $MessageEndpointAlive.afterDelivery(MessageEndpointProxy.java:126)
       at
org .apache .activemq .ra.MessageEndpointProxy.afterDelivery(MessageEndpointProxy.java:65)
       at
org .apache .activemq.ra.ServerSessionImpl.afterDelivery(ServerSessionImpl.java: 216) at org.apache.activemq.ActiveMQSession.run(ActiveMQSession.java:751)
       at
org.apache.activemq.ra.ServerSessionImpl.run(ServerSessionImpl.java: 165)
       at
org .apache.geronimo.connector.work.WorkerContext.run(WorkerContext.java: 290)
       at
org .apache .geronimo.connector.work.pool.NamedRunnable.run(NamedRunnable.java:32) at org.apache.geronimo.pool.ThreadPool$1.run(ThreadPool.java: 214)
       at
org.apache.geronimo.pool.ThreadPool $ContextClassLoaderRunnable.run(ThreadPool.java:344)
       at
java.util.concurrent.ThreadPoolExecutor $Worker.runTask(ThreadPoolExecutor.java:885)
       at
java.util.concurrent.ThreadPoolExecutor $Worker.run(ThreadPoolExecutor.java:907)
       at java.lang.Thread.run(Thread.java:619)

I'm looking for solution for this issue.

Thanks
Beniamin
--
View this message in context: 
http://www.nabble.com/HOWL-exception-tp16047940s134p16047940.html
Sent from the Apache Geronimo - Users mailing list archive at Nabble.com.


Reply via email to