2 Replies Latest reply: Aug 6, 2010 8:35 AM by Greybird-Oracle RSS

    Environment invalid because of a missing file

    789192
      I've got an application which uses BDB JE 4.0.92 quite intensive. It was running without restarts (and so opening/closing bdb environment) for about a week and suddenly the following exception began to occur on every operation with environment:

      com.sleepycat.je.EnvironmentFailureException: (JE 4.0.92) Environment must be closed, caused by: com.sleepycat.je.EnvironmentFailureException: Environment invalid because of previous exception: (JE 4.0.92) var/db/bdb_userNode fetchTarget of 0x3151/0x44b2638 parent IN=729921304 IN class=com.sleepycat.je.tree.DBIN lastFullVersion=0x3189/0x13616b0 parent.getDirty()=false state=0 LOG_FILE_NOT_FOUND: Log file missing, log is likely invalid. Environment is invalid and must be closed.
      at com.sleepycat.je.EnvironmentFailureException.wrapSelf(EnvironmentFailureException.java:197) [je-4.0.92.jar:na]
      at com.sleepycat.je.dbi.EnvironmentImpl.checkIfInvalid(EnvironmentImpl.java:1403) [je-4.0.92.jar:na]
      at com.sleepycat.je.Environment.checkEnv(Environment.java:2118) [je-4.0.92.jar:na]
      at com.sleepycat.je.Environment.beginTransactionInternal(Environment.java:1281) [je-4.0.92.jar:na]
      at com.sleepycat.je.Environment.beginTransaction(Environment.java:1263) [je-4.0.92.jar:na]
      at ru.bdirect.overkings.cluster.tx.BdbTxManager.beginTransaction(BdbTxManager.java:76) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.cluster.tx.BdbTransactionalAspect.beginTransaction(BdbTransactionalAspect.java:78) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      ... 14 common frames omitted
      Caused by: com.sleepycat.je.EnvironmentFailureException: Environment invalid because of previous exception: (JE 4.0.92) var/db/bdb_userNode fetchTarget of 0x3151/0x44b2638 parent IN=729921304 IN class=com.sleepycat.je.tree.DBIN lastFullVersion=0x3189/0x13616b0 parent.getDirty()=false state=0 LOG_FILE_NOT_FOUND: Log file missing, log is likely invalid. Environment is invalid and must be closed.
      at com.sleepycat.je.tree.IN.fetchTarget(IN.java:1241) [je-4.0.92.jar:na]
      at com.sleepycat.je.tree.BIN.fetchTarget(BIN.java:1300) [je-4.0.92.jar:na]
      at com.sleepycat.je.dbi.CursorImpl.fetchCurrent(CursorImpl.java:2370) [je-4.0.92.jar:na]
      at com.sleepycat.je.dbi.CursorImpl.fetchCurrent(CursorImpl.java:2397) [je-4.0.92.jar:na]
      at com.sleepycat.je.dbi.CursorImpl.getCurrentAlreadyLatched(CursorImpl.java:1418) [je-4.0.92.jar:na]
      at com.sleepycat.je.Cursor.searchInternal(Cursor.java:2174) [je-4.0.92.jar:na]
      at com.sleepycat.je.Cursor.searchAllowPhantoms(Cursor.java:2058) [je-4.0.92.jar:na]
      at com.sleepycat.je.Cursor.search(Cursor.java:1926) [je-4.0.92.jar:na]
      at com.sleepycat.je.SecondaryCursor.search(SecondaryCursor.java:1364) [je-4.0.92.jar:na]
      at com.sleepycat.je.SecondaryCursor.getSearchKey(SecondaryCursor.java:1089) [je-4.0.92.jar:na]
      at com.sleepycat.util.keyrange.RangeCursor.doGetSearchKey(RangeCursor.java:963) [je-4.0.92.jar:na]
      at com.sleepycat.util.keyrange.RangeCursor.getFirst(RangeCursor.java:302) [je-4.0.92.jar:na]
      at com.sleepycat.util.keyrange.RangeCursor.getNext(RangeCursor.java:420) [je-4.0.92.jar:na]
      at com.sleepycat.persist.BasicCursor.next(BasicCursor.java:81) [je-4.0.92.jar:na]
      at com.sleepycat.persist.BasicIterator.hasNext(BasicIterator.java:50) [je-4.0.92.jar:na]
      at ru.bdirect.overkings.cluster.datastore.BdbDsUtils.entitiesFromCursor(BdbDsUtils.java:86) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.cluster.datastore.BdbDsUtils.entitiesFromCursor(BdbDsUtils.java:73) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.cluster.datastore.BdbDsUtils.entitiesFromCursor(BdbDsUtils.java:41) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.ds.ItemsDatasource.getItemsByContainer_aroundBody14(ItemsDatasource.java:122) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.ds.ItemsDatasource$AjcClosure15.run(ItemsDatasource.java:1) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at org.aspectj.runtime.reflect.JoinPointImpl.proceed(JoinPointImpl.java:221) [aspectjweaver-1.6.5.jar:1.6.5]
      at ru.bdirect.overkings.cluster.tx.BdbTransactionalAspect.aroundBDBTxMethod(BdbTransactionalAspect.java:138) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.ds.ItemsDatasource.getItemsByContainer(ItemsDatasource.java:121) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.items.containers.PersistentContainer.<init>(PersistentContainer.java:66) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.items.containers.ParentContainer.<init>(ParentContainer.java:47) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.usernode.items.containers.BindingContainer.<init>(BindingContainer.java:31) [user-node-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.usernode.items.containers.InventoryContainer.<init>(InventoryContainer.java:17) [user-node-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.usernode.items.containers.BfConsumablesContainer.<init>(BfConsumablesContainer.java:45) [user-node-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.usernode.items.containers.CostumeContainer.<init>(CostumeContainer.java:49) [user-node-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.usernode.items.containers.QuestObjectivesContainer.<init>(QuestObjectivesContainer.java:29) [user-node-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.usernode.items.containers.BagContainer.<init>(BagContainer.java:18) [user-node-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.usernode.items.UsernodeContainersManager.createInstance(UsernodeContainersManager.java:219) [user-node-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.items.AbstractContainersManager.createInstance(AbstractContainersManager.java:212) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.items.AbstractContainersManager.getContainer(AbstractContainersManager.java:71) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.items.containers.ParentContainer$ChildContainersIterator.findNext(ParentContainer.java:189) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.items.containers.ParentContainer$ChildContainersIterator.hasNext(ParentContainer.java:166) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.usernode.items.ContainersCollection$ContainersIterator.goToNext(ContainersCollection.java:140) [user-node-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.usernode.items.ContainersCollection$ContainersIterator.hasNext(ContainersCollection.java:102) [user-node-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.items.AbstractContainersCollection$ItemsIterator.goToNext(AbstractContainersCollection.java:190) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.items.AbstractContainersCollection$ItemsIterator.hasNext(AbstractContainersCollection.java:174) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.items.AbstractContainersCollection.countPrototypesImpl(AbstractContainersCollection.java:143) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.items.AbstractContainersCollection.countPrototypes(AbstractContainersCollection.java:115) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.usernode.UserNodeForBfImpl.getCharacterWithEquipment_aroundBody0(UserNodeForBfImpl.java:172) [user-node-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.usernode.UserNodeForBfImpl$AjcClosure1.run(UserNodeForBfImpl.java:1) [user-node-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at org.aspectj.runtime.reflect.JoinPointImpl.proceed(JoinPointImpl.java:221) [aspectjweaver-1.6.5.jar:1.6.5]
      at ru.bdirect.overkings.cluster.tx.BdbTransactionalAspect.aroundBDBTxMethod(BdbTransactionalAspect.java:138) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.usernode.UserNodeForBfImpl.getCharacterWithEquipment(UserNodeForBfImpl.java:156) [user-node-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at sun.reflect.GeneratedMethodAccessor105.invoke(Unknown Source) [na:na]
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [na:1.6.0_17]
      at java.lang.reflect.Method.invoke(Method.java:597) [na:1.6.0_17]
      at lmbrd.zn.cluster.rmi.HandlerMethod.invoke(HandlerMethod.java:35) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.cluster.b2b.InvocationTask.handle(InvocationTask.java:72) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      at ru.bdirect.overkings.cluster.b2b.InvocationTask.run(InvocationTask.java:44) [commons-1.0-SNAPSHOT.jar:1.0-SNAPSHOT]
      ... 3 common frames omitted
      Caused by: java.io.FileNotFoundException: var/db/bdb_userNode/00003151.jdb (No such file or directory)
      at java.io.RandomAccessFile.open(Native Method) [na:1.6.0_17]
      at java.io.RandomAccessFile.<init>(RandomAccessFile.java:212) [na:1.6.0_17]
      at java.io.RandomAccessFile.<init>(RandomAccessFile.java:98) [na:1.6.0_17]
      at com.sleepycat.je.log.FileManager$1.<init>(FileManager.java:993) [je-4.0.92.jar:na]
      at com.sleepycat.je.log.FileManager.openFileHandle(FileManager.java:992) [je-4.0.92.jar:na]
      at com.sleepycat.je.log.FileManager.getFileHandle(FileManager.java:888) [je-4.0.92.jar:na]
      at com.sleepycat.je.log.LogManager.getLogSource(LogManager.java:1073) [je-4.0.92.jar:na]
      at com.sleepycat.je.log.LogManager.getLogEntry(LogManager.java:779) [je-4.0.92.jar:na]
      at com.sleepycat.je.log.LogManager.getLogEntryAllowInvisibleAtRecovery(LogManager.java:743) [je-4.0.92.jar:na]
      at com.sleepycat.je.tree.IN.fetchTarget(IN.java:1225) [je-4.0.92.jar:na]
      ... 55 common frames omitted

      I've tried to restart the application, environment opened successfuly and everything worked fine for a couple of hours, then the same error started to occur again. Not sure what exactly triggers the error, later I opened the environment and ran through all primary indicies reading all entries without getting any errors.
        • 1. Re: Environment invalid because of a missing file
          3962
          We are seeing similar errors

          Caused by: com.sleepycat.je.EnvironmentFailureException: (JE 4.0.103) Environment must be closed, caused by: com.sleepycat.je.EnvironmentFailureException: Environment invalid because of previous exception: (JE 4.0.103) /var/folders/ln/ln-MDvR7E+W0bSTkbtq1cIQkK1w/-Tmp-/asap1719020141006426527je fetchTarget of 0x0/0xe545d parent IN=106116 IN class=com.sleepycat.je.tree.BIN lastFullVersion=0xffffffff/0xffffffff parent.getDirty()=true state=2 LOG_FILE_NOT_FOUND: Log file missing, log is likely invalid. Environment is invalid and must be closed.
               at com.sleepycat.je.EnvironmentFailureException.wrapSelf(EnvironmentFailureException.java:196)
               at com.sleepycat.je.dbi.EnvironmentImpl.checkIfInvalid(EnvironmentImpl.java:1450)
               at com.sleepycat.je.log.FileManager.writeLogBuffer(FileManager.java:1283)
               at com.sleepycat.je.log.LogBufferPool.writeBufferToFile(LogBufferPool.java:244)
               at com.sleepycat.je.log.LogBufferPool.getWriteBuffer(LogBufferPool.java:181)
               at com.sleepycat.je.log.LogManager.serialLogInternal(LogManager.java:577)
               at com.sleepycat.je.log.SyncedLogManager.serialLog(SyncedLogManager.java:39)
               at com.sleepycat.je.log.LogManager.multiLog(LogManager.java:387)
               at com.sleepycat.je.log.LogManager.log(LogManager.java:328)
               at com.sleepycat.je.tree.IN.logInternal(IN.java:3193)
               at com.sleepycat.je.tree.IN.log(IN.java:3114)
               at com.sleepycat.je.evictor.Evictor.evictIN(Evictor.java:986)
               at com.sleepycat.je.evictor.Evictor.evictIN(Evictor.java:899)
               at com.sleepycat.je.evictor.Evictor.evictBatch(Evictor.java:414)
               at com.sleepycat.je.evictor.Evictor.doEvict(Evictor.java:316)
               at com.sleepycat.je.evictor.Evictor.doCriticalEviction(Evictor.java:344)
               at com.sleepycat.je.dbi.EnvironmentImpl.criticalEviction(EnvironmentImpl.java:2396)
               at com.sleepycat.je.dbi.CursorImpl.criticalEviction(CursorImpl.java:313)
               at com.sleepycat.je.Cursor.endMoveCursor(Cursor.java:2759)
               at com.sleepycat.je.Cursor.putAllowPhantoms(Cursor.java:1804)
               at com.sleepycat.je.Cursor.putNoNotify(Cursor.java:1756)
               at com.sleepycat.je.Cursor.putNotify(Cursor.java:1689)
               at com.sleepycat.je.Cursor.putInternal(Cursor.java:1626)
               at com.sleepycat.je.Database.putInternal(Database.java:1186)
               at com.sleepycat.je.Database.put(Database.java:1058)
               at com.sleepycat.persist.PrimaryIndex.putNoReturn(PrimaryIndex.java:479)
               at com.sleepycat.persist.PrimaryIndex.putNoReturn(PrimaryIndex.java:442)
               at com.vpharm.application.asap.data.DataStore.writeResult(DataStore.java:147)
               at com.vpharm.application.asap.data.DatabaseResultsBuilder.addRecord(DatabaseResultsBuilder.java:154)
               at com.vpharm.application.asap.verdi.CacheSearcher$1.call(CacheSearcher.java:204)
               at com.vpharm.application.asap.verdi.CacheSearcher$1.call(CacheSearcher.java:188)
               ... 5 more
          Caused by: com.sleepycat.je.EnvironmentFailureException: Environment invalid because of previous exception: (JE 4.0.103) /var/folders/ln/ln-MDvR7E+W0bSTkbtq1cIQkK1w/-Tmp-/asap1719020141006426527je fetchTarget of 0x0/0xe545d parent IN=106116 IN class=com.sleepycat.je.tree.BIN lastFullVersion=0xffffffff/0xffffffff parent.getDirty()=true state=2 LOG_FILE_NOT_FOUND: Log file missing, log is likely invalid. Environment is invalid and must be closed.
               at com.sleepycat.je.tree.IN.fetchTarget(IN.java:1256)
               at com.sleepycat.je.tree.BIN.fetchTarget(BIN.java:1321)
               at com.sleepycat.je.dbi.CursorImpl.searchAndPosition(CursorImpl.java:2248)
               at com.sleepycat.je.Cursor.searchInternal(Cursor.java:2097)
               at com.sleepycat.je.Cursor.searchAllowPhantoms(Cursor.java:2067)
               at com.sleepycat.je.Cursor.search(Cursor.java:1935)
               at com.sleepycat.je.Database.get(Database.java:905)
               at com.sleepycat.persist.PrimaryIndex.get(PrimaryIndex.java:588)
               at com.sleepycat.persist.PrimaryIndex.get(PrimaryIndex.java:578)
               at com.vpharm.application.asap.data.DataStore.getDatabaseResult(DataStore.java:156)
          Caused by: java.io.FileNotFoundException: /var/folders/ln/ln-MDvR7E+W0bSTkbtq1cIQkK1w/-Tmp-/asap1719020141006426527je/00000000.jdb (No such file or directory)
               at java.io.RandomAccessFile.open(Native Method)
               at java.io.RandomAccessFile.<init>(RandomAccessFile.java:212)
               at java.io.RandomAccessFile.<init>(RandomAccessFile.java:98)
               at com.sleepycat.je.log.FileManager$1.<init>(FileManager.java:996)
               at com.sleepycat.je.log.FileManager.openFileHandle(FileManager.java:995)
               at com.sleepycat.je.log.FileManager.getFileHandle(FileManager.java:891)
               at com.sleepycat.je.log.LogManager.getLogSource(LogManager.java:1072)
               at com.sleepycat.je.log.LogManager.getLogEntry(LogManager.java:778)
               at com.sleepycat.je.log.LogManager.getLogEntryAllowInvisibleAtRecovery(LogManager.java:742)
               at com.sleepycat.je.tree.IN.fetchTarget(IN.java:1239)
          • 2. Re: Environment invalid because of a missing file
            Greybird-Oracle
            Trevor,

            I'm working on this problem off-forum. Could you please send me email: mark.hayes at o.com.

            Thanks,
            --mark