This discussion is archived
1 Reply Latest reply: May 14, 2013 2:14 PM by Andrei Costache, Oracle RSS

BDB v5.0.73 - EnvironmentFailureException: (JE 5.0.73) JAVA_ERROR

1008845 Newbie
Currently Being Moderated
Hi there!

Im using java berkeley db as caching tool between two applications (backend application is quite slow so we cache some requests). We are caching xml data (one request xml can be ~4MB), if xml data exists we update the cache entry, if does not exists we insert new entry. there can be many concurrent hits same time.

Currently I tested with JMeter and with 10 Threads all works fine but if I increase to 20 Threads following error occurs:

+2013-05-14 15:31:15,914 [ERROR] CacheImpl - error occured while trying to get data from cache.+
com.sleepycat.je.EnvironmentFailureException: (JE 5.0.73) JAVA_ERROR: Java Error occurred, recovery may not be possible. fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0
+     at com.sleepycat.je.dbi.EnvironmentImpl.checkIfInvalid(EnvironmentImpl.java:1507)+
+     at com.sleepycat.je.Environment.checkEnv(Environment.java:2185)+
+     at com.sleepycat.je.Environment.beginTransactionInternal(Environment.java:1313)+
+     at com.sleepycat.je.Environment.beginTransaction(Environment.java:1284)+
+     at com.ebcont.redbull.bullchecker.cache.impl.CacheImpl.get(CacheImpl.java:157)+
+     at com.ebcont.redbull.bullchecker.handler.EndpointHandler.doPerform(EndpointHandler.java:132)+
+     at com.ebcont.redbull.bullchecker.WSCacheEndpointServlet.doPost(WSCacheEndpointServlet.java:86)+
+     at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)+
+     at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)+
+     at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)+
+     at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)+
+     at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)+
+     at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)+
+     at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)+
+     at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)+
+     at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)+
+     at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)+
+     at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:861)+
+     at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:606)+
+     at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)+
+     at java.lang.Thread.run(Unknown Source)+
Caused by: java.lang.OutOfMemoryError: Java heap space
+2013-05-14 15:31:15,939 [ERROR] CacheImpl - error occured while trying to get data from cache.+
com.sleepycat.je.EnvironmentFailureException: (JE 5.0.73) JAVA_ERROR: Java Error occurred, recovery may not be possible. fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0 fetchTarget of 0x11/0x1d1d parent IN=8 IN class=com.sleepycat.je.tree.IN lastFullVersion=0x1b/0x4cd lastLoggedVersion=0x1b/0x4cd parent.getDirty()=false state=0
+     at com.sleepycat.je.dbi.EnvironmentImpl.checkIfInvalid(EnvironmentImpl.java:1507)+
+     at com.sleepycat.je.Environment.checkEnv(Environment.java:2185)+
+     at com.sleepycat.je.Environment.beginTransactionInternal(Environment.java:1313)+
+     at com.sleepycat.je.Environment.beginTransaction(Environment.java:1284)+
+     at com.ebcont.redbull.bullchecker.cache.impl.CacheImpl.get(CacheImpl.java:157)+
+     at com.ebcont.redbull.bullchecker.handler.EndpointHandler.doPerform(EndpointHandler.java:132)+
+     at com.ebcont.redbull.bullchecker.WSCacheEndpointServlet.doPost(WSCacheEndpointServlet.java:86)+
+     at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)+
+     at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)+
+     at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)+
+     at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)+
+     at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)+
+     at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)+
+     at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)+
+     at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)+
+     at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)+
+     at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)+
+     at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:861)+
+     at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:606)+
+     at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)+
+     at java.lang.Thread.run(Unknown Source)+

after restarting the server I get following error while trying to get data from cache:

java.lang.OutOfMemoryError: Java heap space
+     at com.sleepycat.je.log.LogUtils.readBytesNoLength(LogUtils.java:365)+
+     at com.sleepycat.je.tree.LN.readFromLog(LN.java:786)+
+     at com.sleepycat.je.log.entry.LNLogEntry.readBaseLNEntry(LNLogEntry.java:196)+
+     at com.sleepycat.je.log.entry.LNLogEntry.readEntry(LNLogEntry.java:130)+
+     at com.sleepycat.je.log.LogManager.getLogEntryFromLogSource(LogManager.java:1008)+
+     at com.sleepycat.je.log.LogManager.getLogEntry(LogManager.java:848)+
+     at com.sleepycat.je.log.LogManager.getLogEntryAllowInvisibleAtRecovery(LogManager.java:809)+
+     at com.sleepycat.je.tree.IN.fetchTarget(IN.java:1412)+
+     at com.sleepycat.je.tree.BIN.fetchTarget(BIN.java:1251)+
+     at com.sleepycat.je.dbi.CursorImpl.fetchCurrent(CursorImpl.java:2261)+
+     at com.sleepycat.je.dbi.CursorImpl.getCurrentAlreadyLatched(CursorImpl.java:1466)+
+     at com.sleepycat.je.dbi.CursorImpl.getNext(CursorImpl.java:1593)+
+     at com.sleepycat.je.Cursor.retrieveNextAllowPhantoms(Cursor.java:2924)+
+     at com.sleepycat.je.Cursor.retrieveNextNoDups(Cursor.java:2801)+
+     at com.sleepycat.je.Cursor.retrieveNext(Cursor.java:2775)+
+     at com.sleepycat.je.Cursor.getNextNoDup(Cursor.java:1244)+
+     at com.ebcont.redbull.bullchecker.cache.impl.BDBCacheImpl.getStoredKeys(BDBCacheImpl.java:244)+
+     at com.ebcont.redbull.bullchecker.CacheStatisticServlet.doPost(CacheStatisticServlet.java:108)+
+     at com.ebcont.redbull.bullchecker.CacheStatisticServlet.doGet(CacheStatisticServlet.java:74)+
+     at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)+
+     at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)+
+     at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)+
+     at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)+
+     at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)+
+     at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)+
+     at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)+
+     at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)+
+     at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)+
+     at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)+
+     at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:861)+
+     at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:606)+
+     at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)+


my bdb configuration:
environmentConfig.setReadOnly(false);
databaseConfig.setReadOnly(false);
environmentConfig.setAllowCreate(true);
databaseConfig.setAllowCreate(true);
environmentConfig.setTransactional(true);
databaseConfig.setTransactional(true);
environmentConfig.setCachePercent(60);
environmentConfig.setLockTimeout(2000, TimeUnit.MILLISECONDS);
environmentConfig.setCacheMode(CacheMode.DEFAULT);


environment path: C:/tmp/berkeleydb
Tomcat JVM Parameters: Initial Memory Pool: 1024
Maximum Memory Pool: 2048
Server: Windows Server 2008
Memory: 8 GB

Edited by: 1005842 on 14.05.2013 07:22

Edited by: 1005842 on 14.05.2013 07:23

Edited by: 1005842 on 14.05.2013 07:37
  • 1. Re: BDB v5.0.73 - EnvironmentFailureException: (JE 5.0.73) JAVA_ERROR
    Andrei Costache, Oracle Journeyer
    Currently Being Moderated
    Hi,

    The stack trace shows an OOME error due to running out of heap space.
    Could you detail what is the exact Java version you are using, on what OS, and what are the JVM options, in particular the max heap size (-Xmx), you are using?
    Also, what is the JE cache size you use? (if you do not set any of the MAX_MEMORY or MAX_MEMORY_PERCENT then the JE cache size will default to 60% of the JVM max heap size)

    You should look into the way you are using transactions, cursors etc. It might be possible that you are using long running transactions that accumulate a large number of locks, or you might be opening more and more transactions without closing/completing them (by aborting or committing them). Is any of this the case for your application? You can check the lock and transaction statistics using Environment.getStats() and respectively Environment.getTransactionStats().

    Aside properly ending/closing transactions and cursors, you should also examine your cache statistics to understand the memory profile. See the following documentation sections on this:
    http://docs.oracle.com/cd/E17277_02/html/GettingStartedGuide/cachesize.html
    http://www.oracle.com/technetwork/database/berkeleydb/je-faq-096044.html#HowcanIestimatemyapplicationsoptimalcachesize
    http://www.oracle.com/technetwork/database/berkeleydb/je-faq-096044.html#WhyshouldtheJEcachebelargeenoughtoholdtheBtreeinternalnodes


    Regards,
    Andrei

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points