From: Andrzej J. T. <an...@ch...> - 2010-02-02 02:27:17
|
Just rebuilt my application eXist database from scratch, and then put 25K xml documents into it. Latest trunk from SVN. I seem to have a 6GB 0000000000.log file in my data directory after the storing of the 25K xml documents. When does this log file get shrunk? Is there any way to force it to be sync'ed and shrunk? So I left the database alone for about an hour after the reload. And then shut it down (2 minute delay on shutdown) using a normal Tomcat shutdown. But now when I restart the database I get the long running "Scanning journal [=====..." task as the database starts up in the Tomcat container. What's with this massive journal scanning on restart? It's like my transactions never committed and so it's reprocessing the monster 6GB log file. Never used to do this....back a month or so ago. Some help in explaining what might be going on would be appreciated. Thanks! -- Andrzej Taramina Chaeron Corporation: Enterprise System Solutions http://www.chaeron.com |
From: Andrzej J. T. <an...@ch...> - 2010-02-02 02:50:45
|
More on this issue: On the recovery I get the following exceptions in the exist log: 2010-02-01 20:40:01,993 [main] WARN (RecoveryManager.java [doRecovery]:223) - Exception caught while redoing transactions. Aborting recovery. java.lang.ArrayIndexOutOfBoundsException at java.lang.System.arraycopy(Native Method) at org.exist.util.FixedByteArray.copyTo(FixedByteArray.java:41) at org.exist.storage.index.BFile.storeValueHelper(BFile.java:1353) at org.exist.storage.index.BFile.redoStoreValue(BFile.java:1044) at org.exist.storage.index.StoreValueLoggable.redo(StoreValueLoggable.java:94) at org.exist.storage.recovery.RecoveryManager.doRecovery(RecoveryManager.java:217) at org.exist.storage.recovery.RecoveryManager.recover(RecoveryManager.java:154) at org.exist.storage.txn.TransactionManager.runRecovery(TransactionManager.java:137) at org.exist.storage.BrokerPool.initialize(BrokerPool.java:793) at org.exist.storage.BrokerPool.<init>(BrokerPool.java:660) at org.exist.storage.BrokerPool.configure(BrokerPool.java:216) at org.exist.storage.BrokerPool.configure(BrokerPool.java:188) at org.exist.http.servlets.EXistServlet.startup(EXistServlet.java:675) at org.exist.http.servlets.EXistServlet.init(EXistServlet.java:116) at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1173) at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:993) at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:4149) at org.apache.catalina.core.StandardContext.start(StandardContext.java:4458) at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1045) at org.apache.catalina.core.StandardHost.start(StandardHost.java:722) at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1045) at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:443) at org.apache.catalina.core.StandardService.start(StandardService.java:516) at org.apache.catalina.core.StandardServer.start(StandardServer.java:710) at org.apache.catalina.startup.Catalina.start(Catalina.java:583) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.lang.reflect.Method.invoke(Unknown Source) at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:288) at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:413) 2010-02-01 20:40:02,009 [main] WARN (RecoveryManager.java [doRecovery]:225) - Log entry that caused the exception: [0, 1389117] org.exist.storage.index.StoreValueLoggable [BFile] - stored value with tid 1 on page 2 2010-02-01 20:40:02,009 [main] INFO (RecoveryManager.java [doRecovery]:228) - Redo processed 89 out of 26721 transactions. And then the database is unavailable. Very frustrating, not being able to reload a clean database. Any ideas what is causing this? Are there some long running tasks that are not completing after my store of 25K documents? Or are there some shutdown hooks that were put in Jetty, but aren't being executed in Tomcat? Why would the recovery fail? Then again, I'm puzzled why I'm even in recovery mode in the first place. Help! Thx! -- Andrzej Taramina Chaeron Corporation: Enterprise System Solutions http://www.chaeron.com |
From: Wolfgang M. <wol...@ex...> - 2010-02-02 08:17:33
|
The log file should be cleared by the next checkpoint, which should at least occur during shutdown, if not before. It definitely looks like you have a hanging transaction somewhere in the background? Can you get a stack trace from Java to see which thread is hanging? I made some changes to the shutdown listeners yesterday, and I wonder if they are causing the issue - though those changes were limited to jetty only... Wolfgang |
From: Andrzej J. T. <an...@ch...> - 2010-02-02 15:24:52
|
Wolfgang: > The log file should be cleared by the next checkpoint, which should at > least occur during shutdown, if not before. Is there any way to force a checkpoint? Admin task? XQuery function? The reason I ask is that it would be a useful thing to be able to force a checkpoint to happen after a huge bulk store operation, thus guaranteeing that the database is in a good state and fully optimized before you attempt a shutdown. If there isn't such a method, do you think that it would be useful to add an XQuery function (maybe in the system namespece) or this capability to the admin (web and java) clients? If so, then I'ld be happy to add this capability, if you point me in the general direction of how to initiate a checkpoint (eg, what class/method to call in Java). Thx! -- Andrzej Taramina Chaeron Corporation: Enterprise System Solutions http://www.chaeron.com |
From: Wolfgang M. <wol...@ex...> - 2010-02-02 09:07:33
|
Ok, I confirm there's an issue in SVN trunk which causes the shutdown process to hang and blocks any checkpoints. I can reproduce it on one machine. If you are using trunk, don't update just now... Wolfgang |
From: Wolfgang M. <wol...@ex...> - 2010-02-02 10:58:06
|
Found it. The issue was introduced by rev 11074 on January 24. The code acquires a DBBroker instance without releasing it afterwards (this is a fatal violation of the internal API). Please remember that the *only* way to call BrokerPool.get() should be within a try-finally with a call to BrokerPool.release() in the finally clause. Wolfgang |
From: Andrzej J. T. <an...@ch...> - 2010-02-02 14:56:06
|
Wolfgang: > Found it. The issue was introduced by rev 11074 on January 24. The > code acquires a DBBroker instance without releasing it afterwards > (this is a fatal violation of the internal API). Many, many huge thanks for finding and fixing this one! Saves me from reverting both eXIst and out application code. I owe you a good beer for this! > Please remember that the *only* way to call BrokerPool.get() should be > within a try-finally with a call to BrokerPool.release() in the > finally clause. Noted for the future, though it wasn't moi that made that change. -- Andrzej Taramina Chaeron Corporation: Enterprise System Solutions http://www.chaeron.com |
From: Dannes W. <di...@ex...> - 2010-02-02 15:23:17
|
Hi, On Tue, Feb 2, 2010 at 3:55 PM, Andrzej Jan Taramina <an...@ch...>wrote: > I owe you a good beer for this! > Prague is The Place for a good beer... D. -- eXist-db Native XML Database - http://exist-db.org Join us on linked-in: http://www.linkedin.com/groups?gid=35624 |
From: Andrzej J. T. <an...@ch...> - 2010-02-02 15:39:59
|
Dannes: > Prague is The Place for a good beer... I know! I know! Unfortunately, I have a family commitment that weekend, and there would be no way to get back in time for that if I went to Prague. Believe me...I wish I could be there. I would be buying a round (or two) for the whole eXist team in appreciation for all the hard work everyone puts in. Maybe next year in Prague! Or in Minneapolis this summer? -- Andrzej Taramina Chaeron Corporation: Enterprise System Solutions http://www.chaeron.com |
From: Loren C. <lor...@gm...> - 2010-02-02 15:54:55
|
On Feb 2, 2010, at 09:39 AM, Andrzej Jan Taramina wrote: > Dannes: > >> Prague is The Place for a good beer... > > I know! I know! > > Unfortunately, I have a family commitment that weekend, and there would be no way to get back in time for that if I went > to Prague. > > Believe me...I wish I could be there. I would be buying a round (or two) for the whole eXist team in appreciation for > all the hard work everyone puts in. > > Maybe next year in Prague! Or in Minneapolis this summer? I also know of a great place for beer in the Minneapolis/Saint Paul area. A wonderful little brew pub. |
From: Andrzej J. T. <an...@ch...> - 2010-02-02 16:07:32
|
Loren: > I also know of a great place for beer in the Minneapolis/Saint Paul area. A wonderful little brew pub. First round, maybe even two, will be on me at this brew pub of yours! -- Andrzej Taramina Chaeron Corporation: Enterprise System Solutions http://www.chaeron.com |